ENH: Add verbose output to nextstrain remote (and potentially other CLI commands)

[corneliusroemer]

Context

I'm getting an error when uploading but it's not clear what the issue is from the messages I'm getting.

I feel like it would be helpful to have more verbose output to at least have a clue at which point something fails

Description

Add a flag --verbose to nextstrain remote that shows connection attempts etc.

Examples

This should work:

nextstrain remote upload nextstrain.org/groups/neherlab/ncov/belgium auspice-combined/belgium/latest/ncov_belgium.json --verbose

Example use case

This is the error I get, doesn't make much sense in my case

(nextstrain) ubuntu@ip-172-31-15-175:~/ncov-simple-daily-builds$ nextstrain remote upload nextstrain.org/groups/neherlab/ncov/belgium auspice-combined/belgium/latest/ncov_belgium.json auspice-combined/belgium/latest/ncov_belgium_root-sequence.json auspice-combined/belgium/latest/ncov_belgium_tip-frequencies.json 2>&1
Uploading auspice-combined/belgium/latest/ncov_belgium.json as https://nextstrain.org/groups/neherlab/ncov/belgium
Error: The connection to the remote server was severed before the
upload finished.

Retrying may help if the problem happens to be transient (e.g. a
network error like a lost wifi signal), or there might be a bug
somewhere that needs to be fixed.

If retrying after a bit doesn't help, please open a new issue
at <https://github.com/nextstrain/cli/issues/new/choose> and
include the complete output above and the command you were
running.

[huddlej]

@corneliusroemer Can you confirm that this specific error is still a problem with the recent fix to nextstrain.org's authentication framework?

[tsibley]

I think this issue wasn't about the specific error—that's #202—but instead the inability to find out more details of what remote was doing before/when it failed. Hence the enhancement classification instead of bug (and also why I haven't closed this). It's a reasonable request, though low priority and likely to only happen as part of other adjacent work (or as part of systematically adding more opt-in debugging output to all commands).

[corneliusroemer]

Yep, @tsibley correctly guessed at my intentions.

When debugging, I was looking for a --verbose option that would tell me what was tried, which URL was requested, what the error/warnings were exactly - but no such option existed.

Maybe something to bear in mind in the future when adding more functionality. Hence ENH. I agree, it's low priority.

[tsibley]

FWIW, the URL requested is shown in normal output; it's https://nextstrain.org/groups/neherlab/ncov/belgium.

For the actual underlying error, the exception is raised from the original error (itself also chained)—very few places in this codebase use from None—but then that context isn't shown by the global error handler, which does just:

cli/nextstrain/cli/__init__.py

Lines 34 to 36 in 72500a8

	except NextstrainCliError as error:
	warn(error)
	return 1

I agree it'd be useful to have a global way to surface that.

[corneliusroemer]

Just coming back to this as I have the same use case: I would like to understand how nextstrain has parsed this command:

nextstrain build \
          --aws-batch \
          --detach \
          --no-download \
          --cpus 16 \
          --memory 64gib \
          --exec env \
          . \
            envdir env.d snakemake notify_on_deploy \
              --configfiles config/configfile.yaml config/nextstrain_automation.yaml \
              --printshellcmds

which would help me with debugging #272.

A verbosity flag would really be great to have.

But I see here in this issue that you have added a "debugging mode" controlled by NEXTSTRAIN_DEBUG env variable. Would be great if this was documented in nextstrain --help-all or nextstrain build --help-all @tsibley

I just tested that debug logging but it doesn't change the output at all (maybe I had already got that env variable set or there's just no difference).

[corneliusroemer]

Coming back to this again, I would have loved to have --verbose output just now when nextstrain login --no-prompt took a long time (>20 seconds) and not showing anything. Verbose could have showed where it was stuck (i.e. before even sending a network request). I intuitively tacked on a -v just to be reminded that this flag isn't supported. I really wish it was 🙃

The reason nothing happened is just that the cluster is really slow at loading various Python files so even to get the argparse error takes 10 seconds

[victorlin]

@corneliusroemer in your example above, what would you expect the debug output to provide? Argparse validation happens very early on, so there's not much to report. I can only come up with something like this:

DEBUG: Registering parser…
DEBUG: Parsing arguments…
usage: nextstrain [-h]
                  {build,view,deploy,remote,shell,update,setup,check-setup,login,logout,whoami,version,init-shell,authorization,debugger}
                  ...
nextstrain: error: unrecognized arguments: -v

If Python file loading is the bottleneck, these debug messages might also take 10 seconds to appear.

[corneliusroemer]

In the case of nextstrain login --no-prompt I would expect -v to say something like: sending request x to y, receiving response z

No need to say "importing XYZ" of course or argparse stuff. Knowing that things were slow before a request was sent would quickly tell me that it's just slow file system as opposed to network latency etc

Verbose output is always helpful to figure out what's going on, even when you don't see anything as that still tells you that the program is not even somewhere where it would print anything.

Maybe there's a misunderstanding, I don't think we need -v to do anything for the case if adding unrecognized arguments. But to things like nextstrain login.

[victorlin]

I see, the issue is not having any output from nextstrain login --no-prompt while it was doing authentication. That seems reasonable to add.