ENH: provide INFO level logging for an action about to be reran

[yarikoptic]

I do not exactly like increasing verbosity here, but DEBUG level would
be not appropriate -- at that level we display already much more of details
effectively forbidding tracking ongoing activities.

Here is the result of rerunning on some ad-hoc repo (sorry - I have not
scripted it, here is tarball: http://www.onerussian.com/tmp/test-rerun.tgz) which has a merge and some cherry picks

$> datalad rerun --since=
[INFO   ] run commit d4a55bb (md5)
[INFO   ] Making sure inputs are available (this may take some time)
unlock(ok): /home/yoh/proj/datalad/trash/test-rerun/MD5SUMS (file)
[INFO   ] == Command start (output follows) =====
[INFO   ] == Command exit (modification check follows) =====
add(ok): /home/yoh/proj/datalad/trash/test-rerun/MD5SUMS (file)
[INFO   ] run commit 66a4fee (md5)
[INFO   ] Making sure inputs are available (this may take some time)
unlock(ok): /home/yoh/proj/datalad/trash/test-rerun/MD5SUMS (file)
[INFO   ] == Command start (output follows) =====
[INFO   ] == Command exit (modification check follows) =====
add(ok): /home/yoh/proj/datalad/trash/test-rerun/MD5SUMS (file)
[INFO   ] skip-or-pick commit c2275fc c2275fc does not have a command; skipping or cherry picking
run(ok): /home/yoh/proj/datalad/trash/test-rerun (dataset) [c2275fc does not have a command; skipping]
[INFO   ] run commit c406290 (md5)
[INFO   ] Making sure inputs are available (this may take some time)
unlock(ok): /home/yoh/proj/datalad/trash/test-rerun/MD5SUMS (file)
[INFO   ] == Command start (output follows) =====
[INFO   ] == Command exit (modification check follows) =====
add(ok): /home/yoh/proj/datalad/trash/test-rerun/MD5SUMS (file)
[INFO   ] run commit b3ac331 (touching file2)
unlock(ok): /home/yoh/proj/datalad/trash/test-rerun/file2 (file)
[INFO   ] == Command start (output follows) =====
[INFO   ] == Command exit (modification check follows) =====
add(ok): /home/yoh/proj/datalad/trash/test-rerun/file2 (file)
[INFO   ] skip-or-pick commit 5c0bad1 5c0bad1 does not have a command; skipping or cherry picking
run(ok): /home/yoh/proj/datalad/trash/test-rerun (dataset) [5c0bad1 does not have a command; skipping]
[INFO   ] merge commit ce53a0d
run(ok): /home/yoh/proj/datalad/trash/test-rerun (dataset)
[INFO   ] run commit d962936 (md5)
[INFO   ] Making sure inputs are available (this may take some time)
unlock(ok): /home/yoh/proj/datalad/trash/test-rerun/MD5SUMS (file)
[INFO   ] == Command start (output follows) =====
[INFO   ] == Command exit (modification check follows) =====
add(ok): /home/yoh/proj/datalad/trash/test-rerun/MD5SUMS (file)
action summary:
  add (ok: 5)
  get (notneeded: 20)
  run (ok: 3)
  save (notneeded: 5)
  unlock (ok: 5)

Also note that we do already report "run" results records for "strip-or-pick"
but not for actual "run". Even if we start reporting more of "run" records, I
still see value in reporting on "what about to happen" in the log. Or may be
we somehow could provide "progress indication" across rerun steps? after all
it is jus a loop (over a generator though)

Closes #3584

[codecov]

Codecov Report

Merging #4764 into maint will increase coverage by 0.10%.
The diff coverage is 100.00%.

@@            Coverage Diff             @@
##            maint    #4764      +/-   ##
==========================================
+ Coverage   89.59%   89.69%   +0.10%     
==========================================
  Files         288      288              
  Lines       40209    40377     +168     
==========================================
+ Hits        36027    36218     +191     
+ Misses       4182     4159      -23     

Impacted Files	Coverage Δ
datalad/interface/rerun.py	96.62% <100.00%> (+0.21%)	⬆️
datalad/core/local/tests/test_status.py	96.33% <0.00%> (-2.59%)	⬇️
datalad/ui/progressbars.py	77.19% <0.00%> (-1.17%)	⬇️
datalad/downloaders/http.py	84.55% <0.00%> (-0.94%)	⬇️
datalad/core/distributed/clone.py	88.62% <0.00%> (-0.65%)	⬇️
datalad/support/exceptions.py	83.41% <0.00%> (-0.44%)	⬇️
datalad/tests/utils.py	87.15% <0.00%> (-0.20%)	⬇️
datalad/__init__.py	90.78% <0.00%> (-0.07%)	⬇️
datalad/support/tests/test_sshconnector.py	97.66% <0.00%> (-0.06%)	⬇️
datalad/core/local/tests/test_diff.py	97.23% <0.00%> (-0.02%)	⬇️
... and 44 more

---

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 2633d5e...b0985fb. Read the comment docs.

[kyleam]

Assuming others are in favor of this, it's fine with me.

skip-or-pick commit 5c0bad1 5c0bad1 does not have a command; skipping or cherry picking

That's missing a separator between "5c0bad1 5c0bad1".

Given that you're in _rerun already when emitting this log message, I think it's worth considering just sprinkling in plain log messages at the appropriate spot once it's known what action will be taken (e.g., lgr.info("Cherry pick commit %s", res_hexsha)).

[yarikoptic]

@mih @bpoldrack et al - any feedback would be welcome so I know how/if to proceed!

[yarikoptic]

2nd ping to @mih and @bpoldrack

[yarikoptic]

That's missing a separator between "5c0bad1 5c0bad1".

Thanks -- added ;

I think it's worth considering just sprinkling in plain log messages at the appropriate spot

"lazy" me prefers having a single generic invocation on the top of the loop instead of adding largely duplicate log invocations at the spots. So I left it as is

[kyleam]

"lazy" me prefers having a single generic invocation on the top of the loop instead of adding largely duplicate log invocations at the spots. So I left it as is

I think that makes it harder to read with no benefit (despite describing it as "generic"), but it's not a big deal and it's okay as is.