Repository: borgbackup/borg

Issue:
wrong original size in borg create
Hello,
[borg 1.1.1  python 3.4.5 CentOs 6]
I tried 2 times with same command but different files ( oracle dump ) and both times I had
an original size reported twice bigger than the real one.
The file is 109 GB.
I tried even with smaller files but the problem did not appear.

```
# borg create -p --stats /opt/mnt/test.borg::test2 ads_orcl_daily_dmp_5
------------------------------------------------------------------------------
Archive name: test2
Archive fingerprint: ba34d3cb846d521388a14ea5cf1b9a8addb114de386a042738b99fac01e48a42
Time (start): Thu, 2017-10-26 12:33:18
Time (end):   Thu, 2017-10-26 13:33:38
Duration: 1 hours 20.12 seconds
Number of files: 1
Utilization of max. archive size: 0%
------------------------------------------------------------------------------
                       Original size      Compressed size    Deduplicated size
This archive:              232.90 GB            205.06 GB            102.53 GB
All archives:              232.90 GB            205.06 GB            102.53 GB

                       Unique chunks         Total chunks
Chunk index:                   44512                89022
------------------------------------------------------------------------------
```
giuseppe


Discussion:
codecov-io: # [Codecov](https://codecov.io/gh/borgbackup/borg/pull/3234?src=pr&el=h1) Report
> Merging [#3234](https://codecov.io/gh/borgbackup/borg/pull/3234?src=pr&el=desc) into [master](https://codecov.io/gh/borgbackup/borg/commit/2b79aade368140026562a7b515f02952ddc3474e?src=pr&el=desc) will **decrease** coverage by `0.14%`.
> The diff coverage is `80%`.

[![Impacted file tree graph](https://codecov.io/gh/borgbackup/borg/pull/3234/graphs/tree.svg?src=pr&token=LssEpmW3o4&width=650&height=150)](https://codecov.io/gh/borgbackup/borg/pull/3234?src=pr&el=tree)

```diff
@@            Coverage Diff            @@
##           master   #3234      +/-   ##
=========================================
- Coverage   85.94%   85.8%   -0.15%     
=========================================
  Files          36      36              
  Lines        8981    8991      +10     
  Branches     1490    1491       +1     
=========================================
- Hits         7719    7715       -4     
- Misses        848     860      +12     
- Partials      414     416       +2
```


| [Impacted Files](https://codecov.io/gh/borgbackup/borg/pull/3234?src=pr&el=tree) | Coverage Δ | |
|---|---|---|
| [src/borg/archiver.py](https://codecov.io/gh/borgbackup/borg/pull/3234?src=pr&el=tree#diff-c3JjL2JvcmcvYXJjaGl2ZXIucHk=) | `86.11% <100%> (-0.42%)` | :arrow_down: |
| [src/borg/archive.py](https://codecov.io/gh/borgbackup/borg/pull/3234?src=pr&el=tree#diff-c3JjL2JvcmcvYXJjaGl2ZS5weQ==) | `83.76% <77.77%> (+0.1%)` | :arrow_up: |
| [src/borg/helpers/misc.py](https://codecov.io/gh/borgbackup/borg/pull/3234?src=pr&el=tree#diff-c3JjL2JvcmcvaGVscGVycy9taXNjLnB5) | `81.73% <0%> (-6.09%)` | :arrow_down: |

------

[Continue to review full report at Codecov](https://codecov.io/gh/borgbackup/borg/pull/3234?src=pr&el=continue).
> **Legend** - [Click here to learn more](https://docs.codecov.io/docs/codecov-delta)
> `Δ = absolute <relative> (impact)`, `ø = not affected`, `? = missing data`
> Powered by [Codecov](https://codecov.io/gh/borgbackup/borg/pull/3234?src=pr&el=footer). Last update [2b79aad...46f1513](https://codecov.io/gh/borgbackup/borg/pull/3234?src=pr&el=lastupdated). Read the [comment docs](https://docs.codecov.io/docs/pull-request-comments).

enkore: Wasn't this observed in 1.1, which does this differently?
ThomasWaldmann: IIRC I tried to reproduce in master and found it broken. Maybe it has other reasons in 1.1, that could be.
ThomasWaldmann: output of fixed code:
```
(borg-env) tw@tux:~/w/borg$ borg init -e none repo
(borg-env) tw@tux:~/w/borg$ borg create --stats repo::arch src
------------------------------------------------------------------------------
Archive name: arch
Archive fingerprint: 2225d8d8fc2424e179a8c311ff950c936a429c4e598389552212e6777b6b0e7b
Time (start): Thu, 2017-11-02 17:39:43
Time (end):   Thu, 2017-11-02 17:39:45
Duration: 2.13 seconds
Number of files: 471
Utilization of max. archive size: 0%
------------------------------------------------------------------------------
                       Original size      Compressed size    Deduplicated size
This archive:              146.66 MB             39.29 MB             36.87 MB
All archives:              146.66 MB             39.29 MB             36.87 MB

                       Unique chunks         Total chunks
Chunk index:                     499                  508
------------------------------------------------------------------------------


(borg-env) tw@tux:~/w/borg$ borg create --stats repo::arch2 src
------------------------------------------------------------------------------
Archive name: arch2
Archive fingerprint: 9b75b27a7e31d8afdf9b05c402bdc9ff80fea5f9d56e54a9a3282ce33aa5d4b0
Time (start): Thu, 2017-11-02 17:40:22
Time (end):   Thu, 2017-11-02 17:40:22
Duration: 0.09 seconds
Number of files: 471
Utilization of max. archive size: 0%
------------------------------------------------------------------------------
                       Original size      Compressed size    Deduplicated size
This archive:              146.66 MB             39.29 MB             41.75 kB
All archives:              293.33 MB             78.58 MB             36.91 MB

                       Unique chunks         Total chunks
Chunk index:                     501                 1016
------------------------------------------------------------------------------
```
ThomasWaldmann: output of master code:
```
(borg-env) tw@tux:~/w/borg$ borg init -e none repo
(borg-env) tw@tux:~/w/borg$ borg create --stats repo::arch src
------------------------------------------------------------------------------
Archive name: arch
Archive fingerprint: 7adea46884c14504608ef2f4cbb54f6e5a8a0607b5d1b4d2e84cabcc2867cf13
Time (start): Thu, 2017-11-02 17:43:44
Time (end):   Thu, 2017-11-02 17:43:46
Duration: 2.50 seconds
Number of files: 0
Utilization of max. archive size: 0%
------------------------------------------------------------------------------
                       Original size      Compressed size    Deduplicated size
This archive:              106.12 kB             41.73 kB             41.73 kB
All archives:              146.66 MB             39.29 MB             36.87 MB

                       Unique chunks         Total chunks
Chunk index:                     499                  508
------------------------------------------------------------------------------


(borg-env) tw@tux:~/w/borg$ borg create --stats repo::arch2 src
------------------------------------------------------------------------------
Archive name: arch2
Archive fingerprint: efbfeb5728b5d8f287320b3567b5ae13d2723ea228a7360131a2fb10ed2e36f0
Time (start): Thu, 2017-11-02 17:44:00
Time (end):   Thu, 2017-11-02 17:44:00
Duration: 0.09 seconds
Number of files: 0
Utilization of max. archive size: 0%
------------------------------------------------------------------------------
                       Original size      Compressed size    Deduplicated size
This archive:              106.12 kB             41.73 kB             41.73 kB
All archives:              293.33 MB             78.58 MB             36.91 MB

                       Unique chunks         Total chunks
Chunk index:                     501                 1016
------------------------------------------------------------------------------
```
"Number of files" and "This Archive" stats obviously broken.


Patch:
diff --git a/src/borg/archive.py b/src/borg/archive.py
index e04731e8..a8fbba91 100644
--- a/src/borg/archive.py
+++ b/src/borg/archive.py
@@ -65,6 +65,16 @@ def update(self, size, csize, unique):
         if unique:
             self.usize += csize
 
+    def __add__(self, other):
+        if not isinstance(other, Statistics):
+            raise TypeError('can only add Statistics objects')
+        stats = Statistics(self.output_json)
+        stats.osize = self.osize + other.osize
+        stats.csize = self.csize + other.csize
+        stats.usize = self.usize + other.usize
+        stats.nfiles = self.nfiles + other.nfiles
+        return stats
+
     summary = "{label:15} {stats.osize_fmt:>20s} {stats.csize_fmt:>20s} {stats.usize_fmt:>20s}"
 
     def __str__(self):
diff --git a/src/borg/archiver.py b/src/borg/archiver.py
index d678bb28..03f66137 100644
--- a/src/borg/archiver.py
+++ b/src/borg/archiver.py
@@ -49,7 +49,7 @@
 from .helpers import BaseFormatter, ItemFormatter, ArchiveFormatter
 from .helpers import format_timedelta, format_file_size, parse_file_size, format_archive
 from .helpers import safe_encode, remove_surrogates, bin_to_hex, prepare_dump_dict
-from .helpers import interval, prune_within, prune_split, PRUNING_PATTERNS
+from .helpers import interval, prune_within, prune_split
 from .helpers import timestamp
 from .helpers import get_cache_dir
 from .helpers import Manifest, AI_HUMAN_SORT_KEYS
@@ -482,6 +482,7 @@ def create_inner(archive, cache, fso):
                 if args.progress:
                     archive.stats.show_progress(final=True)
                 args.stats |= args.json
+                archive.stats += fso.stats
                 if args.stats:
                     if args.json:
                         json_print(basic_json_data(manifest, cache=cache, extra={
@@ -1333,48 +1334,45 @@ def do_prune(self, args, repository, manifest, key):
         # that is newer than a successfully completed backup - and killing the successful backup.
         archives = [arch for arch in archives_checkpoints if arch not in checkpoints]
         keep = []
-        # collect the rule responsible for the keeping of each archive in this dict
-        # keys are archive ids, values are a tuple
-        #   (<rulename>, <how many archives were kept by this rule so far >)
-        kept_because = {}
-
-        # find archives which need to be kept because of the keep-within rule
         if args.within:
-            keep += prune_within(archives, args.within, kept_because)
-
-        # find archives which need to be kept because of the various time period rules
-        for rule in PRUNING_PATTERNS.keys():
-            num = getattr(args, rule, None)
-            if num is not None:
-                keep += prune_split(archives, rule, num, kept_because)
-
+            keep += prune_within(archives, args.within)
+        if args.secondly:
+            keep += prune_split(archives, '%Y-%m-%d %H:%M:%S', args.secondly, keep)
+        if args.minutely:
+            keep += prune_split(archives, '%Y-%m-%d %H:%M', args.minutely, keep)
+        if args.hourly:
+            keep += prune_split(archives, '%Y-%m-%d %H', args.hourly, keep)
+        if args.daily:
+            keep += prune_split(archives, '%Y-%m-%d', args.daily, keep)
+        if args.weekly:
+            keep += prune_split(archives, '%G-%V', args.weekly, keep)
+        if args.monthly:
+            keep += prune_split(archives, '%Y-%m', args.monthly, keep)
+        if args.yearly:
+            keep += prune_split(archives, '%Y', args.yearly, keep)
         to_delete = (set(archives) | checkpoints) - (set(keep) | set(keep_checkpoints))
         stats = Statistics()
         with Cache(repository, key, manifest, do_files=False, lock_wait=self.lock_wait) as cache:
             list_logger = logging.getLogger('borg.output.list')
-            # set up counters for the progress display
-            to_delete_len = len(to_delete)
-            archives_deleted = 0
+            if args.output_list:
+                # set up counters for the progress display
+                to_delete_len = len(to_delete)
+                archives_deleted = 0
             for archive in archives_checkpoints:
                 if archive in to_delete:
                     if args.dry_run:
-                        log_message = 'Would prune:'
+                        if args.output_list:
+                            list_logger.info('Would prune:     %s' % format_archive(archive))
                     else:
-                        archives_deleted += 1
-                        log_message = 'Pruning archive (%d/%d):' % (archives_deleted, to_delete_len)
+                        if args.output_list:
+                            archives_deleted += 1
+                            list_logger.info('Pruning archive: %s (%d/%d)' % (format_archive(archive),
+                                                                              archives_deleted, to_delete_len))
                         Archive(repository, key, manifest, archive.name, cache,
                                 progress=args.progress).delete(stats, forced=args.forced)
                 else:
-                    if is_checkpoint(archive.name):
-                        log_message = 'Keeping checkpoint archive:'
-                    else:
-                        log_message = 'Keeping archive (rule: {rule} #{num}):'.format(
-                            rule=kept_because[archive.id][0], num=kept_because[archive.id][1]
-                        )
-                if args.output_list:
-                    list_logger.info("{message:<40} {archive}".format(
-                        message=log_message, archive=format_archive(archive)
-                    ))
+                    if args.output_list:
+                        list_logger.info('Keeping archive: %s' % format_archive(archive))
             if to_delete and not args.dry_run:
                 manifest.write()
                 repository.commit(save_space=args.save_space)
diff --git a/src/borg/helpers/misc.py b/src/borg/helpers/misc.py
index b0fbb203..e33b46f0 100644
--- a/src/borg/helpers/misc.py
+++ b/src/borg/helpers/misc.py
@@ -4,7 +4,7 @@
 import os.path
 import platform
 import sys
-from collections import deque, OrderedDict
+from collections import deque
 from datetime import datetime, timezone, timedelta
 from itertools import islice
 from operator import attrgetter
@@ -17,44 +17,22 @@
 from .. import chunker
 
 
-def prune_within(archives, hours, kept_because):
+def prune_within(archives, hours):
     target = datetime.now(timezone.utc) - timedelta(seconds=hours * 3600)
-    kept_counter = 0
-    result = []
-    for a in archives:
-        if a.ts > target:
-            kept_counter += 1
-            kept_because[a.id] = ("within", kept_counter)
-            result.append(a)
-    return result
-
-
-PRUNING_PATTERNS = OrderedDict([
-    ("secondly", '%Y-%m-%d %H:%M:%S'),
-    ("minutely", '%Y-%m-%d %H:%M'),
-    ("hourly", '%Y-%m-%d %H'),
-    ("daily", '%Y-%m-%d'),
-    ("weekly", '%G-%V'),
-    ("monthly", '%Y-%m'),
-    ("yearly", '%Y'),
-])
-
-
-def prune_split(archives, rule, n, kept_because=None):
+    return [a for a in archives if a.ts > target]
+
+
+def prune_split(archives, pattern, n, skip=[]):
     last = None
     keep = []
-    pattern = PRUNING_PATTERNS[rule]
-    if kept_because is None:
-        kept_because = {}
     if n == 0:
         return keep
     for a in sorted(archives, key=attrgetter('ts'), reverse=True):
         period = to_localtime(a.ts).strftime(pattern)
         if period != last:
             last = period
-            if a.id not in kept_because:
+            if a not in skip:
                 keep.append(a)
-                kept_because[a.id] = (rule, len(keep))
                 if len(keep) == n:
                     break
     return keep


Test patch:
diff --git a/src/borg/testsuite/archiver.py b/src/borg/testsuite/archiver.py
index 29fc50f7..c3a66632 100644
--- a/src/borg/testsuite/archiver.py
+++ b/src/borg/testsuite/archiver.py
@@ -6,7 +6,6 @@
 import os
 import pstats
 import random
-import re
 import shutil
 import socket
 import stat
@@ -1732,11 +1731,12 @@ def test_prune_repository(self):
         self.cmd('create', self.repository_location + '::test3.checkpoint.1', src_dir)
         self.cmd('create', self.repository_location + '::test4.checkpoint', src_dir)
         output = self.cmd('prune', '--list', '--dry-run', self.repository_location, '--keep-daily=2')
-        assert re.search(r'Would prune:\s+test1', output)
+        self.assert_in('Keeping archive: test2', output)
+        self.assert_in('Would prune:     test1', output)
         # must keep the latest non-checkpoint archive:
-        assert re.search(r'Keeping archive \(rule: daily #1\):\s+test2', output)
+        self.assert_in('Keeping archive: test2', output)
         # must keep the latest checkpoint archive:
-        assert re.search(r'Keeping checkpoint archive:\s+test4.checkpoint', output)
+        self.assert_in('Keeping archive: test4.checkpoint', output)
         output = self.cmd('list', self.repository_location)
         self.assert_in('test1', output)
         self.assert_in('test2', output)
@@ -1766,8 +1766,8 @@ def test_prune_repository_save_space(self):
         self.cmd('create', self.repository_location + '::test1', src_dir)
         self.cmd('create', self.repository_location + '::test2', src_dir)
         output = self.cmd('prune', '--list', '--stats', '--dry-run', self.repository_location, '--keep-daily=2')
-        assert re.search(r'Keeping archive \(rule: daily #1\):\s+test2', output)
-        assert re.search(r'Would prune:\s+test1', output)
+        self.assert_in('Keeping archive: test2', output)
+        self.assert_in('Would prune:     test1', output)
         self.assert_in('Deleted data:', output)
         output = self.cmd('list', self.repository_location)
         self.assert_in('test1', output)
@@ -1784,8 +1784,8 @@ def test_prune_repository_prefix(self):
         self.cmd('create', self.repository_location + '::bar-2015-08-12-10:00', src_dir)
         self.cmd('create', self.repository_location + '::bar-2015-08-12-20:00', src_dir)
         output = self.cmd('prune', '--list', '--dry-run', self.repository_location, '--keep-daily=2', '--prefix=foo-')
-        assert re.search(r'Keeping archive \(rule: daily #1\):\s+foo-2015-08-12-20:00', output)
-        assert re.search(r'Would prune:\s+foo-2015-08-12-10:00', output)
+        self.assert_in('Keeping archive: foo-2015-08-12-20:00', output)
+        self.assert_in('Would prune:     foo-2015-08-12-10:00', output)
         output = self.cmd('list', self.repository_location)
         self.assert_in('foo-2015-08-12-10:00', output)
         self.assert_in('foo-2015-08-12-20:00', output)
@@ -1805,8 +1805,8 @@ def test_prune_repository_glob(self):
         self.cmd('create', self.repository_location + '::2015-08-12-10:00-bar', src_dir)
         self.cmd('create', self.repository_location + '::2015-08-12-20:00-bar', src_dir)
         output = self.cmd('prune', '--list', '--dry-run', self.repository_location, '--keep-daily=2', '--glob-archives=2015-*-foo')
-        assert re.search(r'Keeping archive \(rule: daily #1\):\s+2015-08-12-20:00-foo', output)
-        assert re.search(r'Would prune:\s+2015-08-12-10:00-foo', output)
+        self.assert_in('Keeping archive: 2015-08-12-20:00-foo', output)
+        self.assert_in('Would prune:     2015-08-12-10:00-foo', output)
         output = self.cmd('list', self.repository_location)
         self.assert_in('2015-08-12-10:00-foo', output)
         self.assert_in('2015-08-12-20:00-foo', output)
diff --git a/src/borg/testsuite/helpers.py b/src/borg/testsuite/helpers.py
index 8d191974..15c029f5 100644
--- a/src/borg/testsuite/helpers.py
+++ b/src/borg/testsuite/helpers.py
@@ -1,10 +1,11 @@
 import hashlib
+import io
 import os
 import shutil
 import sys
 from argparse import ArgumentTypeError
 from datetime import datetime, timezone, timedelta
-from time import sleep
+from time import mktime, strptime, sleep
 
 import pytest
 
@@ -332,56 +333,40 @@ def test(self):
 
 class MockArchive:
 
-    def __init__(self, ts, id):
+    def __init__(self, ts):
         self.ts = ts
-        self.id = id
 
     def __repr__(self):
-        return "{0}: {1}".format(self.id, self.ts.isoformat())
-
-
-@pytest.mark.parametrize(
-    "rule,num_to_keep,expected_ids", [
-        ("yearly", 3, (13, 2, 1)),
-        ("monthly", 3, (13, 8, 4)),
-        ("weekly", 2, (13, 8)),
-        ("daily", 3, (13, 8, 7)),
-        ("hourly", 3, (13, 10, 8)),
-        ("minutely", 3, (13, 10, 9)),
-        ("secondly", 4, (13, 12, 11, 10)),
-        ("daily", 0, []),
-    ]
-)
-def test_prune_split(rule, num_to_keep, expected_ids):
-    def subset(lst, ids):
-        return {i for i in lst if i.id in ids}
-
-    archives = [
-        # years apart
-        MockArchive(datetime(2015, 1, 1, 10, 0, 0, tzinfo=timezone.utc), 1),
-        MockArchive(datetime(2016, 1, 1, 10, 0, 0, tzinfo=timezone.utc), 2),
-        MockArchive(datetime(2017, 1, 1, 10, 0, 0, tzinfo=timezone.utc), 3),
-        # months apart
-        MockArchive(datetime(2017, 2, 1, 10, 0, 0, tzinfo=timezone.utc), 4),
-        MockArchive(datetime(2017, 3, 1, 10, 0, 0, tzinfo=timezone.utc), 5),
-        # days apart
-        MockArchive(datetime(2017, 3, 2, 10, 0, 0, tzinfo=timezone.utc), 6),
-        MockArchive(datetime(2017, 3, 3, 10, 0, 0, tzinfo=timezone.utc), 7),
-        MockArchive(datetime(2017, 3, 4, 10, 0, 0, tzinfo=timezone.utc), 8),
-        # minutes apart
-        MockArchive(datetime(2017, 10, 1, 9, 45, 0, tzinfo=timezone.utc), 9),
-        MockArchive(datetime(2017, 10, 1, 9, 55, 0, tzinfo=timezone.utc), 10),
-        # seconds apart
-        MockArchive(datetime(2017, 10, 1, 10, 0, 1, tzinfo=timezone.utc), 11),
-        MockArchive(datetime(2017, 10, 1, 10, 0, 3, tzinfo=timezone.utc), 12),
-        MockArchive(datetime(2017, 10, 1, 10, 0, 5, tzinfo=timezone.utc), 13),
-    ]
-    kept_because = {}
-    keep = prune_split(archives, rule, num_to_keep, kept_because)
-
-    assert set(keep) == subset(archives, expected_ids)
-    for item in keep:
-        assert kept_because[item.id][0] == rule
+        return repr(self.ts)
+
+
+class PruneSplitTestCase(BaseTestCase):
+
+    def test(self):
+
+        def local_to_UTC(month, day):
+            """Convert noon on the month and day in 2013 to UTC."""
+            seconds = mktime(strptime('2013-%02d-%02d 12:00' % (month, day), '%Y-%m-%d %H:%M'))
+            return datetime.fromtimestamp(seconds, tz=timezone.utc)
+
+        def subset(lst, indices):
+            return {lst[i] for i in indices}
+
+        def dotest(test_archives, n, skip, indices):
+            for ta in test_archives, reversed(test_archives):
+                self.assert_equal(set(prune_split(ta, '%Y-%m', n, skip)),
+                                  subset(test_archives, indices))
+
+        test_pairs = [(1, 1), (2, 1), (2, 28), (3, 1), (3, 2), (3, 31), (5, 1)]
+        test_dates = [local_to_UTC(month, day) for month, day in test_pairs]
+        test_archives = [MockArchive(date) for date in test_dates]
+
+        dotest(test_archives, 3, [], [6, 5, 2])
+        dotest(test_archives, -1, [], [6, 5, 2, 0])
+        dotest(test_archives, 3, [test_archives[6]], [5, 2, 0])
+        dotest(test_archives, 3, [test_archives[5]], [6, 2, 0])
+        dotest(test_archives, 3, [test_archives[4]], [6, 5, 2])
+        dotest(test_archives, 0, [], [])
 
 
 class IntervalTestCase(BaseTestCase):
@@ -425,19 +410,14 @@ def subset(lst, indices):
 
         def dotest(test_archives, within, indices):
             for ta in test_archives, reversed(test_archives):
-                kept_because = {}
-                keep = prune_within(ta, interval(within), kept_because)
-                self.assert_equal(set(keep),
+                self.assert_equal(set(prune_within(ta, interval(within))),
                                   subset(test_archives, indices))
-                assert all("within" == kept_because[a.id][0] for a in keep)
 
         # 1 minute, 1.5 hours, 2.5 hours, 3.5 hours, 25 hours, 49 hours
         test_offsets = [60, 90*60, 150*60, 210*60, 25*60*60, 49*60*60]
         now = datetime.now(timezone.utc)
         test_dates = [now - timedelta(seconds=s) for s in test_offsets]
-        test_archives = [
-            MockArchive(date, i) for i, date in enumerate(test_dates)
-        ]
+        test_archives = [MockArchive(date) for date in test_dates]
 
         dotest(test_archives, '1H', [0])
         dotest(test_archives, '2H', [0, 1])