Repository: datalad/datalad

Issue:
Result suppression issues
I've noticed a couple of rough edges with the recent "suppress similar results" feature.

For demonstration purposes, here's a script saves a number of files equal to the number passed as the first argument.

<details>
<summary>script</summary>

```sh
#!/bin/sh

set -eu

cd "$(mktemp -d --tmpdir dl-XXXXXXX)"
datalad create >/dev/null 2>&1

ntimes=${1:-20}
for i in $(seq 1 "$ntimes")
do
    echo "$i content" >foo-$(printf "%03d" $i)
done

echo "There are $(find . -name "foo-*" | wc -l) files to save\n"
datalad save
```

</details>

All the output below is with 0.12.4-574-gcedcb9e69f.

For ten files, I expected to see all those files.  That's what happens, but there is also a message about -1 suppressed messages.

```
There are 10 files to save

add(ok): foo-001 (file)
add(ok): foo-002 (file)
add(ok): foo-003 (file)
add(ok): foo-004 (file)
add(ok): foo-005 (file)
add(ok): foo-006 (file)
add(ok): foo-007 (file)
add(ok): foo-008 (file)
add(ok): foo-009 (file)
add(ok): foo-010 (file)
  [-1 similar messages have been suppressed]
save(ok): . (dataset)
action summary:
  add (ok: 10)
  save (ok: 1)
```

There is a similar negative number count below the suppression threshold of 10:

```
There are 5 files to save

add(ok): foo-001 (file)
add(ok): foo-002 (file)
add(ok): foo-003 (file)
add(ok): foo-004 (file)
add(ok): foo-005 (file)
  [-6 similar messages have been suppressed]
save(ok): . (dataset)
action summary:
  add (ok: 5)
  save (ok: 1)
```

Right above the limit, there is an odd 0 count:

```
There are 11 files to save

add(ok): foo-001 (file)
add(ok): foo-002 (file)
add(ok): foo-003 (file)
add(ok): foo-004 (file)
add(ok): foo-005 (file)
add(ok): foo-006 (file)
add(ok): foo-007 (file)
add(ok): foo-008 (file)
add(ok): foo-009 (file)
add(ok): foo-010 (file)
add(ok): foo-011 (file)
  [0 similar messages have been suppressed]
save(ok): . (dataset)
action summary:
  add (ok: 11)
  save (ok: 1)
```

Once we get to 12, things look pretty good, though I think the intent was for the results to start being suppress at 10 rather 11.

```
There are 12 files to save

add(ok): foo-001 (file)
add(ok): foo-002 (file)
add(ok): foo-003 (file)
add(ok): foo-004 (file)
add(ok): foo-005 (file)
add(ok): foo-006 (file)
add(ok): foo-007 (file)
add(ok): foo-008 (file)
add(ok): foo-009 (file)
add(ok): foo-010 (file)
add(ok): foo-011 (file)
  [1 similar messages have been suppressed]
save(ok): . (dataset)
action summary:
  add (ok: 12)
  save (ok: 1)
```

Discussion:

Patch:
diff --git a/datalad/interface/utils.py b/datalad/interface/utils.py
index 3ad582302..db03e38dc 100644
--- a/datalad/interface/utils.py
+++ b/datalad/interface/utils.py
@@ -42,8 +42,10 @@ from datalad.utils import (
 from datalad.support.gitrepo import GitRepo
 from datalad.support.exceptions import IncompleteResultsError
 from datalad import cfg as dlcfg
-from datalad.dochelpers import exc_str
-
+from datalad.dochelpers import (
+    exc_str,
+    single_or_plural,
+)
 
 from datalad.ui import ui
 import datalad.support.ansi_colors as ac
@@ -512,6 +514,17 @@ def default_result_renderer(res):
                 if res.get('message', None) else ''))
 
 
+def _display_suppressed_message(nsimilar, ndisplayed):
+    # +1 because there was the original result + nsimilar displayed.
+    n_suppressed = nsimilar - ndisplayed + 1
+    if n_suppressed > 0:
+        ui.message('  [{} similar {} been suppressed]'
+                   .format(n_suppressed,
+                           single_or_plural("message has",
+                                            "messages have",
+                                            n_suppressed, False)))
+
+
 def _process_results(
         results,
         cmd_class,
@@ -534,7 +547,6 @@ def _process_results(
     result_repetitions = 0
     # how many repetitions to show, before suppression kicks in
     render_n_repetitions = 10
-    result_suppression_msg = '  [{} similar messages have been suppressed]'
 
     for res in results:
         if not res or 'action' not in res:
@@ -583,15 +595,14 @@ def _process_results(
             if res.get('status', None) != 'notneeded' \
                     and trimmed_result == last_result:
                 # this is a similar report, suppress if too many, but count it
+                result_repetitions += 1
                 if result_repetitions < render_n_repetitions:
                     default_result_renderer(res)
-                result_repetitions += 1
             else:
                 # this one is new, first report on any prev. suppressed results
                 # by number, and then render this fresh one
-                if result_repetitions:
-                    ui.message(result_suppression_msg.format(
-                        result_repetitions - render_n_repetitions))
+                _display_suppressed_message(
+                    result_repetitions, render_n_repetitions)
                 default_result_renderer(res)
                 result_repetitions = 0
             last_result = trimmed_result
@@ -626,9 +637,8 @@ def _process_results(
                 break
         yield res
     # make sure to report on any issues that we had suppressed
-    if result_repetitions:
-        ui.message(result_suppression_msg.format(
-            result_repetitions - render_n_repetitions))
+    _display_suppressed_message(
+        result_repetitions, render_n_repetitions)
 
 
 def keep_result(res, rfilter, **kwargs):


Test patch:
diff --git a/datalad/interface/tests/test_utils.py b/datalad/interface/tests/test_utils.py
index a754dc1a5..c2a43ea1c 100644
--- a/datalad/interface/tests/test_utils.py
+++ b/datalad/interface/tests/test_utils.py
@@ -23,6 +23,7 @@ from datalad.tests.utils import (
     assert_not_equal,
     assert_not_in,
     assert_raises,
+    assert_re_in,
     assert_repo_status,
     assert_true,
     ok_,
@@ -31,6 +32,7 @@ from datalad.tests.utils import (
     with_tree,
 )
 from datalad.utils import swallow_logs
+from datalad.utils import swallow_outputs
 from datalad.distribution.dataset import (
     Dataset,
     datasetmethod,
@@ -214,17 +216,25 @@ class TestUtils(Interface):
             doc=""""specify the dataset to update.  If
             no dataset is given, an attempt is made to identify the dataset
             based on the input and/or the current working directory""",
-            constraints=EnsureDataset() | EnsureNone()),)
+            constraints=EnsureDataset() | EnsureNone()),
+        result_fn=Parameter(
+            args=tuple(),   # Hide this from the cmdline parser.
+            doc="""Generate the result records with this function
+            rather than using the default logic. `number` will be
+            passed as an argument."""),)
 
     @staticmethod
     @datasetmethod(name='fake_command')
     @eval_results
-    def __call__(number, dataset=None):
-
-        for i in range(number):
-            # this dict will need to have the minimum info required by
-            # eval_results
-            yield {'path': 'some', 'status': 'ok', 'somekey': i, 'action': 'off'}
+    def __call__(number, dataset=None, result_fn=None):
+        if result_fn:
+            yield from result_fn(number)
+        else:
+            for i in range(number):
+                # this dict will need to have the minimum info
+                # required by eval_results
+                yield {'path': 'some', 'status': 'ok', 'somekey': i,
+                       'action': 'off'}
 
 
 def test_eval_results_plus_build_doc():
@@ -273,8 +283,10 @@ def test_eval_results_plus_build_doc():
 
     # test signature:
     from datalad.utils import getargspec
-    assert_equal(getargspec(Dataset.fake_command)[0], ['number', 'dataset'])
-    assert_equal(getargspec(TestUtils.__call__)[0], ['number', 'dataset'])
+    assert_equal(getargspec(Dataset.fake_command)[0],
+                 ['number', 'dataset', 'result_fn'])
+    assert_equal(getargspec(TestUtils.__call__)[0],
+                 ['number', 'dataset', 'result_fn'])
 
 
 def test_result_filter():
@@ -367,3 +379,56 @@ def test_discover_ds_trace(path, otherdir):
         spec = {}
         discover_dataset_trace_to_targets(ds.path, input, [], spec, includeds=eds)
         assert_dict_equal(spec, goal)
+
+
+def test_utils_suppress_similar():
+    tu = TestUtils()
+
+    # Check suppression boundary for straight chain of similar
+    # messages.
+
+    def n_foo(number):
+        for i in range(number):
+            yield dict(action="foo",
+                       status="ok",
+                       path="path{}".format(i))
+
+    with swallow_outputs() as cmo:
+        list(tu(9, result_fn=n_foo, result_renderer="default"))
+        assert_in("path8", cmo.out)
+        assert_not_in("suppressed", cmo.out)
+
+    with swallow_outputs() as cmo:
+        list(tu(10, result_fn=n_foo, result_renderer="default"))
+        assert_in("path9", cmo.out)
+        assert_not_in("suppressed", cmo.out)
+
+    with swallow_outputs() as cmo:
+        list(tu(11, result_fn=n_foo, result_renderer="default"))
+        assert_not_in("path10", cmo.out)
+        assert_re_in(r"[^-0-9]1 .* suppressed", cmo.out, match=False)
+
+    # Check a chain of similar messages, split in half by a distinct one.
+
+    def n_foo_split_by_a_bar(number):
+        half = number // 2 - 1
+        for i in range(number):
+            yield dict(action="foo",
+                       status="ok",
+                       path="path{}".format(i))
+            if i == half:
+                yield dict(action="bar",
+                           status="ok",
+                           path="path")
+
+    with swallow_outputs() as cmo:
+        list(tu(20, result_fn=n_foo_split_by_a_bar, result_renderer="default"))
+        assert_in("path10", cmo.out)
+        assert_in("path19", cmo.out)
+        assert_not_in("suppressed", cmo.out)
+
+    with swallow_outputs() as cmo:
+        list(tu(21, result_fn=n_foo_split_by_a_bar, result_renderer="default"))
+        assert_in("path10", cmo.out)
+        assert_not_in("path20", cmo.out)
+        assert_re_in("[^-0-9]1 .* suppressed", cmo.out, match=False)