Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

OPT: do not bother sleeping when not output was received in the Runner processing of output #3322

Merged
merged 1 commit into from Apr 15, 2019

Conversation

@yarikoptic
Copy link
Member

@yarikoptic yarikoptic commented Apr 12, 2019

As "discussed" in #3319
It could help quite a bit for any runs of git-annex CMD --json (not batched)

@kyleam
Copy link
Contributor

@kyleam kyleam commented Apr 12, 2019

So the sleep came about from e3e8665 (BF: sleep a bit if there were no output in log_online mode to avoid 100% load, 2018-05-08), which was a response to #2478. Won't merging this bring back that issue?

@codecov
Copy link

@codecov codecov bot commented Apr 12, 2019

Codecov Report

Merging #3322 into 0.11.x will increase coverage by 0.02%.
The diff coverage is 100%.

Impacted file tree graph

@@            Coverage Diff             @@
##           0.11.x    #3322      +/-   ##
==========================================
+ Coverage   90.78%   90.81%   +0.02%     
==========================================
  Files         252      252              
  Lines       33087    33087              
==========================================
+ Hits        30039    30048       +9     
+ Misses       3048     3039       -9
Impacted Files Coverage Δ
datalad/cmd.py 95.71% <100%> (ø) ⬆️
datalad/downloaders/tests/test_http.py 91.08% <0%> (+2.22%) ⬆️

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 ab64a6c...cfb1a73. Read the comment docs.

@yarikoptic
Copy link
Member Author

@yarikoptic yarikoptic commented Apr 12, 2019

you are right @kyleam - thanks for looking it up. Getting to the bottom of it. will report back shortly

Whenever there is really no output produced we do get None in
stdout_, while we can also be getting an empty string  in some
cases where we should keep watching.  Mystery is not fully resolved
but at least this one results in asv benchmarks behaving nicely and
no 100% busy datalad in "datalad run sleep 10"
@yarikoptic
Copy link
Member Author

@yarikoptic yarikoptic commented Apr 12, 2019

ok, mystery is not resolved but mitigated by fixing up the check in cfb1a73

FTR I also came up with abomination of an adaptable sleep but I do not think it provided any notable advantage, so decided against it but here is the sketch of a patch (with some debug printouts etc):

diff --git a/.asv b/.asv
--- a/.asv
+++ b/.asv
@@ -1 +1 @@
-Subproject commit 9bdd343b290d86bb71874d7d17e7acc24d074052
+Subproject commit 9bdd343b290d86bb71874d7d17e7acc24d074052-dirty
diff --git a/datalad/cmd.py b/datalad/cmd.py
index 2e4cf837..30c14126 100644
--- a/datalad/cmd.py
+++ b/datalad/cmd.py
@@ -305,12 +305,13 @@ class Runner(object):
                 expect_stderr or expect_fail
         )
 
+        nempty = 0
         while proc.poll() is None:
             # see for a possibly useful approach to processing output
             # in another thread http://codereview.stackexchange.com/a/17959
             # current problem is that if there is no output on stderr
             # it stalls
-            # Monitor if anything was output
+            # Monitor if anything was output and if nothing, sleep a bit
             stdout_, stderr_ = None, None
             if log_stdout_:
                 stdout_ = self._process_one_line(*stdout_args)
@@ -318,6 +319,18 @@ class Runner(object):
             if log_stderr_:
                 stderr_ = self._process_one_line(*stderr_args)
                 stderr += stderr_
+            if stdout_ is None and stderr_ is None:
+            #if not (stdout_ is not None or stderr_ is not None):
+            #if not (stdout_ or stderr_):
+                #print("HERE: %r %r" % (stdout_, stderr_))
+                # no output was generated, so sleep a tiny bit
+                time.sleep(min(0.001, 2**nempty * 0.000001))
+                nempty = min(20, nempty + 1)  # 2**20 ~= 1e6 - more than enough
+                # time.sleep(0.001)
+                pass
+            else:
+                #print("HERE EMPTY")
+                nempty = 0
 
         # Handle possible remaining output
         stdout_, stderr_ = proc.communicate()

@kyleam
Copy link
Contributor

@kyleam kyleam commented Apr 12, 2019

ok, mystery is not resolved but mitigated by fixing up the check in cfb1a73

Nice, thank you.

One thing I wonder is why we even need to call _get_output_online when the call is run(..., log_online=True, log_stdout=False, log_stderr=False). Can't we let that go through to .communicate()? Something like

diff --git a/datalad/cmd.py b/datalad/cmd.py
index d86ea8787..ee941f79b 100644
--- a/datalad/cmd.py
+++ b/datalad/cmd.py
@@ -514,7 +514,7 @@ def run(self, cmd, log_stdout=True, log_stderr=True, log_online=False,
                     self.protocol.end_section(prot_id, prot_exc)

             try:
-                if log_online:
+                if log_online and (log_stdout or log_stderr):
                     out = self._get_output_online(proc,
                                                   log_stdout, log_stderr,
                                                   outputstream, errstream,

@yarikoptic
Copy link
Member Author

@yarikoptic yarikoptic commented Apr 15, 2019

one of the cases which this would change behavior of (don't know yet if with any positive or negative effects) is within sshrun

  /home/yoh/proj/datalad/datalad/venvs/dev/bin/datalad(8)<module>()
-> main()
  /home/yoh/proj/datalad/datalad/datalad/cmdline/main.py(499)main()
-> ret = cmdlineargs.func(cmdlineargs)
  /home/yoh/proj/datalad/datalad/datalad/interface/base.py(626)call_from_parser()
-> ret = cls.__call__(**kwargs)
  /home/yoh/proj/datalad/datalad/datalad/support/sshrun.py(89)__call__()
-> out, err = ssh(cmd, stdin=stdin_, log_output=False)
  /home/yoh/proj/datalad/datalad/datalad/support/sshconnector.py(162)__call__()
-> **kwargs)
> /home/yoh/proj/datalad/datalad/datalad/cmd.py(521)run()
-> out = self._get_output_online(proc,

and the logic there in SSHConnection is

        kwargs = dict(
            log_stdout=log_output, log_stderr=log_output,
            log_online=not log_output
        )

so with such a change we would never hit that _get_output_online when called from it. Adding this additional condition starts to break the tests such as datalad/support/tests/test_gitrepo.py:test_GitRepo_ssh_fetch ... with all the mess of the runner options it is hard to figure out exactly why, so I would prefer to stick to minimal change for now, just fixing the issue.

@kyleam
Copy link
Contributor

@kyleam kyleam commented Apr 15, 2019

@kyleam kyleam merged commit 7a945e1 into datalad:0.11.x Apr 15, 2019
5 checks passed
@yarikoptic yarikoptic added this to the Release 0.11.5 milestone Apr 15, 2019
@yarikoptic yarikoptic deleted the opt-runner branch Apr 23, 2019
yarikoptic added a commit that referenced this issue May 28, 2019
0.11.5 (May 23, 2019) -- stability is not overrated

Should be faster and less buggy, with a few enhancements.

 Fixes

- [create-sibling][]  ([#3318][])
  - Siblings are no longer configured with a post-update hook unless a
    web interface is requested with `--ui`.
  - `git submodule update --init` is no longer called from the
    post-update hook.
  - If `--inherit` is given for a dataset without a superdataset, a
    warning is now given instead of raising an error.
- The internal command runner failed on Python 2 when its `env`
  argument had unicode values.  ([#3332][])
- The safeguard that prevents creating a dataset in a subdirectory
  that already contains tracked files for another repository failed on
  Git versions before 2.14.  For older Git versions, we now warn the
  caller that the safeguard is not active.  ([#3347][])
- A regression introduced in v0.11.1 prevented [save][] from committing
  changes under a subdirectory when the subdirectory was specified as
  a path argument.  ([#3106][])
- A workaround introduced in v0.11.1 made it possible for [save][] to
  do a partial commit with an annex file that has gone below the
  `annex.largefiles` threshold.  The logic of this workaround was
  faulty, leading to files being displayed as typechanged in the index
  following the commit.  ([#3365][])
- The resolve_path() helper confused paths that had a semicolon for
  SSH RIs.  ([#3425][])
- The detection of SSH RIs has been improved.  ([#3425][])

 Enhancements and new features

- The internal command runner was too aggressive in its decision to
  sleep.  ([#3322][])
- The "INFO" label in log messages now retains the default text color
  for the terminal rather than using white, which only worked well for
  terminals with dark backgrounds.  ([#3334][])
- A short flag `-R` is now available for the `--recursion-limit` flag,
  a flag shared by several subcommands.  ([#3340][])
- The authentication logic for [create-sibling-github][] has been
  revamped and now supports 2FA.  ([#3180][])
- New configuration option `datalad.ui.progressbar` can be used to
  configure the default backend for progress reporting ("none", for
  example, results in no progress bars being shown).  ([#3396][])
- A new progress backend, available by setting datalad.ui.progressbar
  to "log", replaces progress bars with a log message upon completion
  of an action.  ([#3396][])
- DataLad learned to consult the [NO_COLOR][] environment variable and
  the new `datalad.ui.color` configuration option when deciding to
  color output.  The default value, "auto", retains the current
  behavior of coloring output if attached to a TTY ([#3407][]).
- [clean][] now removes annex transfer directories, which is useful
  for cleaning up failed downloads. ([#3374][])
- [clone][] no longer refuses to clone into a local path that looks
  like a URL, making its behavior consistent with `git clone`.
  ([#3425][])
- [wtf][]
  - Learned to fall back to the `dist` package if `platform.dist`,
    which has been removed in the yet-to-be-release Python 3.8, does
    not exist.  ([#3439][])
  - Gained a `--section` option for limiting the output to specific
    sections and a `--decor` option, which currently knows how to
    format the output as GitHub's `<details>` section.  ([#3440][])

* tag '0.11.5': (96 commits)
  [DATALAD RUNCMD] make update-changelog
  Version boost and finalize CHANGELOG.md record
  ENH: new Makefile rule linkissues-changelog to link issues, which now will also be prerequisite for update-changelog
  CHANGELOG.md: Add entries for recently merged PRs
  ENH: require "distro" for python >= 3.8
  ENH: compat with python 3.8 which removed .dist -- try distro
  CLN: wtf: Remove unused (and duplicated) import
  DOC: wtf: Avoid double period in -S's description
  ENH: -D|--decor html_details -- to make it ready for pasting to github issue without clutter
  BF: assure bytes while giving to pyperclip upon its demand (on Py2)
  RF: move always present path + type "section" into "location" section, retain order of sections from cmdline
  RF: switch from nargs="*" to action=append for wtf -S
  ENH: wtf -S to specify which sections to query/display (by default -- all)
  MNT: Avoid invalid escape sequences in strings
  BF: export_to_figshare: Don't test identity of string literal
  BF(TST): do not assume user naiveness - treat any url-like looking path as a path
  BF: Check for /, \ or # in the username@hostname part while detecting SSHRI
  CHANGELOG.md: Add entry for gh-3374
  BF: revert back (remove) check for path being PathRI
  BF: list annex-transfer also in cmdline opt choice for "what"
  ...
yarikoptic added a commit that referenced this issue May 28, 2019
0.11.5 (May 23, 2019) -- stability is not overrated

Should be faster and less buggy, with a few enhancements.

 Fixes

- [create-sibling][]  ([#3318][])
  - Siblings are no longer configured with a post-update hook unless a
    web interface is requested with `--ui`.
  - `git submodule update --init` is no longer called from the
    post-update hook.
  - If `--inherit` is given for a dataset without a superdataset, a
    warning is now given instead of raising an error.
- The internal command runner failed on Python 2 when its `env`
  argument had unicode values.  ([#3332][])
- The safeguard that prevents creating a dataset in a subdirectory
  that already contains tracked files for another repository failed on
  Git versions before 2.14.  For older Git versions, we now warn the
  caller that the safeguard is not active.  ([#3347][])
- A regression introduced in v0.11.1 prevented [save][] from committing
  changes under a subdirectory when the subdirectory was specified as
  a path argument.  ([#3106][])
- A workaround introduced in v0.11.1 made it possible for [save][] to
  do a partial commit with an annex file that has gone below the
  `annex.largefiles` threshold.  The logic of this workaround was
  faulty, leading to files being displayed as typechanged in the index
  following the commit.  ([#3365][])
- The resolve_path() helper confused paths that had a semicolon for
  SSH RIs.  ([#3425][])
- The detection of SSH RIs has been improved.  ([#3425][])

 Enhancements and new features

- The internal command runner was too aggressive in its decision to
  sleep.  ([#3322][])
- The "INFO" label in log messages now retains the default text color
  for the terminal rather than using white, which only worked well for
  terminals with dark backgrounds.  ([#3334][])
- A short flag `-R` is now available for the `--recursion-limit` flag,
  a flag shared by several subcommands.  ([#3340][])
- The authentication logic for [create-sibling-github][] has been
  revamped and now supports 2FA.  ([#3180][])
- New configuration option `datalad.ui.progressbar` can be used to
  configure the default backend for progress reporting ("none", for
  example, results in no progress bars being shown).  ([#3396][])
- A new progress backend, available by setting datalad.ui.progressbar
  to "log", replaces progress bars with a log message upon completion
  of an action.  ([#3396][])
- DataLad learned to consult the [NO_COLOR][] environment variable and
  the new `datalad.ui.color` configuration option when deciding to
  color output.  The default value, "auto", retains the current
  behavior of coloring output if attached to a TTY ([#3407][]).
- [clean][] now removes annex transfer directories, which is useful
  for cleaning up failed downloads. ([#3374][])
- [clone][] no longer refuses to clone into a local path that looks
  like a URL, making its behavior consistent with `git clone`.
  ([#3425][])
- [wtf][]
  - Learned to fall back to the `dist` package if `platform.dist`,
    which has been removed in the yet-to-be-release Python 3.8, does
    not exist.  ([#3439][])
  - Gained a `--section` option for limiting the output to specific
    sections and a `--decor` option, which currently knows how to
    format the output as GitHub's `<details>` section.  ([#3440][])

* tag '0.11.5':
  BF: make test for url download more reliable in cases where connection fails
  RF: remove stale commented out duecredit in setup.py.  It has now its own section
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Linked issues

Successfully merging this pull request may close these issues.

None yet

2 participants