Fix and make verbose mode mode useful

[shcheklein]

Mlem version is 🐶 MLEM Version: 0.2.8.dev17+g33031e0

(.venv) ?2 Projects/example-gto % mlem -v deploy run deploy/prod
⏳️ Loading deployment from deploy/prod.mlem
🔗 Loading link to models/churn.pkl.mlem
❌ Unexpected error: [Errno 22] The provided token is malformed or otherwise invalid.
Please report it here: <https://github.com/iterative/mlem/issues>

I would expect for this message to include the full stack trace (otherwise it's not clear what token it talks about).

Also, all options:

mlem -v deploy run deploy/prod
mlem deploy -v run deploy/prod
mlem deploy run -v deploy/prod
mlem deploy run deploy/prod -v

should work fine

[aguschin]

Stack trace is included if you add --tb / --traceback like this: mlem --tb. Should we remove --tb flag and keep a single -v which does both then?

[shcheklein]

thanks, @aguschin , that helps. Yes, this way it differs from DVC. Does it mean DVC does it right and this is not, I don't know- need to think. But from the top of my head- I would just do in -v. It's quite convenient and quite often that you need those two together.

[aguschin]

@mike0sv, what was the initial motivation to do it? Maybe you had some examples/pros/cons in mind?

[mike0sv]

We have mlem -v that enables DEBUG logging and mlem --tb that prints exception if there is any. We can add --tb effect into -v option, but I suggest keep both of them (there might be a lot of logs and it will get messy if you only want to see traceback). We also should add suggestion to use --tb in case of unexpected errors (those are any exceptions not subclassed from MlemError) Unfortunately there is no easy way to allow to set those options anywhere (eg mlem cmd --tb) - this is click restriction

[shcheklein]

Unfortunately there is no easy way to allow to set those options anywhere (eg mlem cmd --tb) - this is click restriction

yep, it's fine in a simple command ... but it completely broke my mind tbh in case when mlem -v deploy run deploy/prod doesn't work ... you kinda expect it to work and it doesn't

We can add --tb effect into -v option,

yes, please :) this is super useful and common use case (e.g. curl -vvvv etc)

[itstargetconfirmed]

Hi Everyone,

I decided to take a shot at this issue.

Decided Approach:

Typer implements a callback that allows users to provide parameters for the main cli application, including printing the application version, printing a traceback and printing logs through verbose mode.

In reviewing the implementation for printing a traceback, it uses the traceback property on the context object to track if the user enabled traceback printing. The traceback property on the context object is enabled by the either explicitly setting the --trackback option or setting the DEBUG property of LOCAL_CONFIG to true. I’ve included the relevant source code below:

ctx.obj = {"traceback": traceback or LOCAL_CONFIG.DEBUG}

We can easily print a traceback through the --verbose option by checking if the verbose option was provided in the cli and changing the state of the traceback property accordingly (shown below).

ctx.obj = {"traceback": traceback or verbose or LOCAL_CONFIG.DEBUG}

User Experience / Messaging Updates

I’ve also implemented the suggestion by @mike0sv to include a message to use the --tb or --traceback option in the case of unexpected errors. I’ve included the error message below:

Use the --tb or --traceback option to include the traceback in the output

Decisions Required:

I have not pushed the code for this bug fix because there’s part of the implementation I’m a bit unsure about.

In mlem/cli/main.py if an unexpected error occurs and the user the provided the --verbose option or --traceback option, the exception is then raised, eventually handled by click/typer and printed to stderr. I’m wondering if instead of raising the exception, we should use traceback.format_exc with the stderr_echo context manager and echo function to write to stderr. With this approach, we can consistently access stdout and stderr through result.stdout and result.stderr respectively for unit tests even if the --traceback option is used.

In the current implementation, if a unit test uses the --traceback option and it throws an exception, result.stderr will not contain the output of the exception (it will be empty).

Current Implementation:

  except Exception as e:  # pylint: disable=broad-except
      error = f"{e.__class__.__module__}.{e.__class__.__name__}"
      if ctx.obj["traceback"]:
          raise

Potential Implementation:

except Exception as e:  # pylint: disable=broad-except
    error = f"{e.__class__.__module__}.{e.__class__.__name__}"
    if ctx.obj["traceback"]:
        with stderr_echo():
            echo(traceback.format_exc())

I’d love to hear your thoughts.

[mike0sv]

If the resulting output is the same, I'd say let's change it. Don't forget to set exit code to 1 since you not re-raising. If output somehow different, let's see both versions and decide

[itstargetconfirmed]

Hi @mike0sv - I’ve attached the output of the current implementation vs the potential implementation. The outputs are different in both implementations; however, I think the potential implementation may be the better approach.

If we look at the current implementation, the extra output is the exception being bubbled up through packages like typer and click. I don’t think this would be valuable to the user since they would only care about the functions called from the point the exception was thrown to where it was caught/printed.

With the potential implementation, the user can focus on the part of the traceback that matters.

Let me know your thoughts.

With Traceback (Current Implementation)

Traceback (most recent call last):
  File "/home/anderson/development/mlem-workspace/example-mlem-get-started/.env/bin/mlem", line 8, in <module>
    sys.exit(app())
  File "/home/anderson/development/mlem-workspace/example-mlem-get-started/.env/lib/python3.8/site-packages/typer/main.py", line 328, in __call__
    raise e
  File "/home/anderson/development/mlem-workspace/example-mlem-get-started/.env/lib/python3.8/site-packages/typer/main.py", line 311, in __call__
    return get_command(self)(*args, **kwargs)
  File "/home/anderson/development/mlem-workspace/example-mlem-get-started/.env/lib/python3.8/site-packages/click/core.py", line 1130, in __call__
    return self.main(*args, **kwargs)
  File "/home/anderson/development/mlem-workspace/example-mlem-get-started/.env/lib/python3.8/site-packages/typer/core.py", line 778, in main
    return _main(
  File "/home/anderson/development/mlem-workspace/example-mlem-get-started/.env/lib/python3.8/site-packages/typer/core.py", line 216, in _main
    rv = self.invoke(ctx)
  File "/home/anderson/development/mlem-workspace/example-mlem-get-started/.env/lib/python3.8/site-packages/click/core.py", line 1657, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/home/anderson/development/mlem-workspace/example-mlem-get-started/.env/lib/python3.8/site-packages/click/core.py", line 1404, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/home/anderson/development/mlem-workspace/example-mlem-get-started/.env/lib/python3.8/site-packages/click/core.py", line 760, in invoke
    return __callback(*args, **kwargs)
  File "/home/anderson/development/mlem-workspace/example-mlem-get-started/.env/lib/python3.8/site-packages/typer/main.py", line 683, in wrapper
    return callback(**use_params)  # type: ignore
  File "/home/anderson/development/mlem-workspace/example-mlem-get-started/.env/lib/python3.8/site-packages/click/decorators.py", line 26, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "/home/anderson/development/mlem-workspace/mlem/mlem/cli/main.py", line 291, in inner
    res = f(*iargs, **ikwargs) or {}
  File "/home/anderson/development/mlem-workspace/mlem/mlem/cli/info.py", line 74, in ls
    raise Exception("This is a test Exception")
Exception: This is a test Exception

With Traceback (Potential Implementation)

Traceback (most recent call last):
  File "/home/anderson/development/mlem-workspace/mlem/mlem/cli/main.py", 
line 292, in inner
    res = f(*iargs, **ikwargs) or {}
  File "/home/anderson/development/mlem-workspace/mlem/mlem/cli/info.py", 
line 74, in ls
    raise Exception("This is a test Exception")
Exception: This is a test Exception

I’ve also think it would be beneficial to include this functionality for MlemError and ValidationError since they also utilize the --traceback option.

[itstargetconfirmed]

Hey @mike0sv

I coded this up just for the fun of it. https://github.com/iterative/mlem/pull/414

You can run this to get an idea of the output if you'd like before we make a decision to include or if we should go an alternative route.

[mike0sv]

Sorry for long delay, I was on vacation :) I reviewed your code. Unfortunately I forgot that it's very convenient to have original exception raised (for tests or if somebody will call cli commands from code for some reason). Is there a way to have the best of both worlds (nice traceback AND original exception)? Alternatively, we can use MLEM_TESTS env to keep original exception for tests