feat: add rich exception formatting, configurable from logging.yaml

[kgpayne]

Closes #2971

• Prettier exception prints #2971

[netlify]

✅ Deploy Preview for meltano ready!

Name	Link
🔨 Latest commit	0e72439
🔍 Latest deploy log	https://app.netlify.com/sites/meltano/deploys/6315fb17a9c0c60009067bb0
😎 Deploy Preview	https://deploy-preview-6640--meltano.netlify.app/guide/logging
📱 Preview on mobile	Toggle QR Code... Use your smartphone camera to open QR code link.

---

To edit notification comments on pull requests, go to your Netlify site settings.

[codecov]

Codecov Report

Merging #6640 (e657cf9) into main (cf3566e) will decrease coverage by 0.07%.
The diff coverage is 63.63%.

❗ Current head e657cf9 differs from pull request most recent head 0e72439. Consider uploading reports for the commit 0e72439 to get more accurate results

@@            Coverage Diff             @@
##             main    #6640      +/-   ##
==========================================
- Coverage   82.99%   82.91%   -0.08%     
==========================================
  Files         178      178              
  Lines       11365    11370       +5     
  Branches     1555     1555              
==========================================
- Hits         9432     9428       -4     
- Misses       1668     1676       +8     
- Partials      265      266       +1     

Impacted Files	Coverage Δ
src/meltano/core/logging/output_logger.py	98.95% <ø> (ø)
src/meltano/core/logging/utils.py	88.23% <ø> (ø)
src/meltano/core/logging/formatters.py	65.00% <63.63%> (-6.43%)	⬇️
src/meltano/core/plugin/settings_service.py	97.10% <0.00%> (-2.90%)	⬇️
src/meltano/core/plugin_discovery_service.py	86.54% <0.00%> (-2.34%)	⬇️
src/meltano/cli/utils.py	81.59% <0.00%> (-1.05%)	⬇️
src/meltano/core/db.py	73.33% <0.00%> (-0.44%)	⬇️
src/meltano/core/elt_context.py	95.89% <0.00%> (+0.68%)	⬆️
src/meltano/cli/elt.py	95.58% <0.00%> (+1.10%)	⬆️

📣 We’re building smart automated test selection to slash your CI/CD build times. Learn more

[kgpayne]

@pandemicsyn looking at this again, and after chatting a bit with AJ, I don't love that OutputLogger requires a Project instance in this PR. Do you think it would be better to add a new format argument (with supported values plain or rich to match the feature flag) rather than allowing the class direct access to the Project instance?

with self.settings_service.feature_flag(
    FeatureFlags.EXCEPTION_FORMATTER, raise_error=False
) as exception_formatter:
    output_logger = OutputLogger(log_file, format=exception_formatter)

The main reason to prefer passing the project over arguments is if we expect to add lots of other feature flags in future for controlling the output format. I guess having the exception_formatter decorator everywhere we instantiate an OutputLogger is also more verbose than just passing a Project instance 🤷‍♂️ What would you do?

[pandemicsyn]

@kgpayne yea, definitely not keen of having to have the OutputLogger aware of projects. OutputLogger should stay as dumb as possible for as long as possible I think.

Could we add the exception_formatter as an option to the existing console log formatter, alongside colors:

meltano/src/meltano/core/logging/formatters.py

Lines 35 to 37 in 0c89bcd

	def console_log_formatter(colors: bool = False) -> None:
	"""Create a logging formatter for console rendering that supports colorization."""
	return _process_formatter(structlog.dev.ConsoleRenderer(colors=colors))

1. This way its an option users can control it via logging.yaml just like color, IMHO i'd kind of expect it to behave that way.
2. Could you also maybe configure it from setup_logging which already has access to the project object and controls log formatting?

If configuring it from setup_logging isn't easily doable (I can't remember if there are gotcha's there related to OutputLogger), then I'd be ok with adding exception_formatter option to OutputLogger. Although, might be better to have it accept a renderer/processor instead, since not every renderer even supports rich formatted exceptions.

[pandemicsyn]

If configuring it from setup_logging isn't easily doable (I can't remember if there are gotcha's there related to OutputLogger),

Forgot how OutputLogger works and that it just injects its own handler. You'll probably still need to pass in a formatter, e.g.

OutputLogger("run.log", meltano.core.logging.console_log_formatter( colors= False, exception_formatter=blah ))

🥷 edit:

To clarify, probably need to enable rich exception formatting in both spots (in our default console renderer that we configure in setup_logging and in OutputLogger), since OutputLogger isn't always in the mix.

[kgpayne]

Ok, I think I have this working. As per @pandemicsyn suggestion above, this PR adds rich formatting to the console_log_formatter via an exception_formatter argument configurable in logging.yaml. It does not add rich formatting to OutputLogger. After some investigation, it seems that class is used primarily for routing output to log files. We also use it in testing to route to stdout/stderr. In both those cases rich exception formatting is undesirable, because of all the ugly raw formatting chars that are dumbed into the traceback. I don't know this part of the code well though, so would appreciate a second pair of 👀 @WillDaSilva looks like you made some logging changes recently 😅

I also can't see an obvious way to feature-flag rich output in addition to logging.yaml config (Florians point 2. above) but agree with the sentiment that:

users can control it via logging.yaml just like color, IMHO i'd kind of expect it to behave that way.

@aaronsteers is logging.yaml fine for enabling rich exception handling, in stead of a feature-flag as originally proposed?

[aaronsteers]

@pandemicsyn and @kgpayne re:

I also can't see an obvious way to feature-flag rich output in addition to logging.yaml config (Florians point 2. above) but agree with the sentiment that:

users can control it via logging.yaml just like color, IMHO i'd kind of expect it to behave that way.

@aaronsteers is logging.yaml fine for enabling rich exception handling, in stead of a feature-flag as originally proposed?

Would it work to let the feature flag dictate what is 'default' when no exception handler is provided?

Here's what I was hoping for:

1. Off by default in first round but we invite people to quickly 'toggle it on' and give us feedback.
2. On by default in a future version after we have a little bit more data on usability.

We likely will not get as many folks creating a new logging.yaml if they don't already have one, versus the ease of use around the feature flag toggle. We could mitigate this by just deciding to have it 'on by default' at launch, and then those who want to turn it off would go down the route of creating a logging.yaml file to customize their output.

I think I would still prefer a feature flag approach to toggle the default (additionally, I mean) , if its not a huge amount of effort to do so, but I'm also okay with just enabling by default in this PR, and then the extra config file is needed to turn it off rather than turning it on.

What do you think?

[pandemicsyn]

Would it work to let the feature flag dictate what is 'default' when no exception handler is provided?

@aaronsteers I think the feature flag could dictate what is default when no logging config is provided, not when no exception handler is provided. If folks are already using logging.yaml's - they won't have an explicit exception handler defined because that's not something we previously required.

Here's what I was hoping for:
Off by default in first round but we invite people to quickly 'toggle it on' and give us feedback.
On by default in a future version after we have a little bit more data on usability.

👍 that makes sense. Just want to draw awareness to the fact that - if this is expected to be a permanent flag, we should maybe consider it becoming a regular cli option at some point. This is just my personal philosophy, but IMHO, feature flags work best when they're not super long-lived (i.e. they exist just to help roll out a feature and get it ready for prime time).

I'm also okay with just enabling by default in this PR, and then the extra config file is needed to turn it off rather than turning it on.

Considering how often we catch flak for our existing colorized output - i definitely have mixed feelings about turning it on by default without at least seeing an example of it, but as long as:

1. it doesn't magically turn on for folks with existing logging.yaml's and break their prod log handling
2. theres an easy way for folks to turn it off

I probably wouldn't object too much 😁

Requested has been addressed

[aaronsteers]

@edgarrmondragon / @pandemicsyn - Would we block on this codecov CI alarm?: https://github.com/meltano/meltano/pull/6640/checks?check_run_id=8139607011

@pandemicsyn - Regarding the default behavior and how the interplay between feature flag and log config should play out, I think we're close to path forward. Will try a zoom real quick to talk through. Otherwise will post back here with my thoughts shortly.

[edgarrmondragon]

@edgarrmondragon / @pandemicsyn - Would we block on this codecov CI alarm?: https://github.com/meltano/meltano/pull/6640/checks?check_run_id=8139607011

@aaronsteers I think the function has simple enough inputs and output that it'd be quick to add a few tests that validate the resulting formatter has the right attributes.

[aaronsteers]

Regarding the default behavior and how the interplay between feature flag and log config should play out, I think we're close to path forward. Will try a zoom real quick to talk through. Otherwise will post back here with my thoughts shortly.

• We'll default to rich enabled for console_log_formatter specifically.
• @kgpayne - Based on whether or not you have a way to use color=false and rich exceptions:
  • If yes (can do no-color rich exceptions): then simply apply no-color at the same time
  • If no (rich exceptions not compatible with no-color, or too difficult to figure out at this time): then force-disable rich when `color=false.
• No feature flag needed.
• No formatting flag needed (can remove).
• Non-console formatters (e.g., key-value and json), will be unchanged (never use rich exceptions)

@pandemicsyn - does this look right to you too?

cc @kgpayne - hopefully this unblocks you to finalize the PR.

[kgpayne]

@aaronsteers (cc @pandemicsyn) if I understand the above correctly, you are asking for i) for rich to be enabled by default and ii) if its possible to have rich enabled but colors disabled?

Based on this feedback from the previous round of discussion:

Here's what I was hoping for:
Off by default in first round but we invite people to quickly 'toggle it on' and give us feedback.
On by default in a future version after we have a little bit more data on usability.

I made the following changes this afternoon:

• added default_exception_formatter feature flag to toggle just the default between "plain" and "rich" (defaulting to plain)

This means:

• users with an existing logging.yaml will be unaffected by the change, and would need to update their yaml to enable rich formatting
• users with no logging.yaml can either use new feature flag to toggle the default exception formatter to rich or create a logging.yaml and enable rich formatting that way
• in both cases formatting with rich is optional

From this:

We'll default to rich enabled for console_log_formatter specifically.
@kgpayne - Based on whether or not you have a way to use color=false and rich exceptions:

• If yes (can do no-color rich exceptions): then simply apply no-color at the same time
• If no (rich exceptions not compatible with no-color, or too difficult to figure out at this time): then force-disable rich when > `color=false.
• No feature flag needed.
• No formatting flag needed (can remove).
• Non-console formatters (e.g., key-value and json), will be unchanged (never use rich exceptions)

It sounds like I need to walk back todays changes and the previous addition of a configurable exception_formatter in favour of either having rich 'always on' (if it is compatible with color=false) or enabled/disabled based on the value of color. Is that correct?

[aaronsteers]

@kgpayne re:

It sounds like I need to walk back todays changes and the previous addition of a configurable exception_formatter in favour of either having rich 'always on' (if it is compatible with color=false) or enabled/disabled based on the value of color. Is that correct?

Yes - let's default this to on, with the following context:

• We prioritize respect of color=false even if that means having to disable rich exception printing. (Will continue working on NO_COLOR compliance in feature: Add support for NO_COLOR env var #6482.)
• If you already have exception_formatter config option, I think it's fine to keep that, so long as it doesn't conflict with no_color and so long as it doesn't have any other averse side affects or affects on the non-console formatters.
  • If the exception_formatter=rich and color=false are incompatible on the other hand, I think we have to remove exception_formatter out and prioritize coherency/compliance with the color setting. (And if we're not sure, we can cut scope by just turning off rich when color=false as mentioned above.)
• If you've already added the default_exception_formatter, I think it's fine to keep that in as well. (With or without the exception_formatter log config, the feature flag is still potentially valuable and we can remove in future if there's no need for it.)

If it's easier to just remove the feature flag and/or the exception_formatter config, that's also fine. I think we need to prioritize getting this shipped so we can progress to work on the NO_COLOR .

[kgpayne]

Ok, I think I have this in good shape:

• Removed the feature flag
• Removed the additional configuration option exception_formatter
• Enabled rich by default
• Added a new custom rich exception formatter with color disabled, for use with the existing colors console logger argument ✨ This mean disabling color does not disable rich formatting of tracebacks, but it does remove all color 💪 Stretch goal win.
• Added rich references in the logging docs

[aaronsteers]

Setup by installing and creating sample project:

pipx install --suffix=6640 --spec=git+https://github.com/meltano/meltano.git@kgpayne/issue2971
meltano6640 init deleteme-temp2

Without debug logging, no change to error report (this is expected):

meltano6640 schedule add invalid-cron-sched --interval=not-legit --job=asdf
not-legit

With debug logging here's the before behavior:

"Before" Behavior

aj@ajs-macbook-pro deleteme-temp2 % meltano --log-level=debug schedule add invalid-cron-sched --interval=not-legit --job=asdf
2022-09-02T19:13:45.893787Z [info     ] Environment 'dev' is active
2022-09-02T19:13:45.989954Z [debug    ] Creating engine <meltano.core.project.Project object at 0x10e1980a0>@sqlite:////Users/aj/Source/deleteme-temp2/.meltano/meltano.db
2022-09-02T19:13:46.340154Z [debug    ] not-legit
Traceback (most recent call last):
  File "/Users/aj/.local/pipx/venvs/meltano/lib/python3.8/site-packages/meltano/cli/__init__.py", line 66, in _run_cli
    cli(obj={"project": None})
  File "/Users/aj/.local/pipx/venvs/meltano/lib/python3.8/site-packages/click/core.py", line 1130, in __call__
    return self.main(*args, **kwargs)
  File "/Users/aj/.local/pipx/venvs/meltano/lib/python3.8/site-packages/meltano/cli/cli.py", line 38, in main
    return super().main(*args, windows_expand_args=False, **kwargs)
  File "/Users/aj/.local/pipx/venvs/meltano/lib/python3.8/site-packages/click/core.py", line 1055, in main
    rv = self.invoke(ctx)
  File "/Users/aj/.local/pipx/venvs/meltano/lib/python3.8/site-packages/meltano/cli/utils.py", line 541, in invoke
    super().invoke(ctx)  # noqa: WPS608
  File "/Users/aj/.local/pipx/venvs/meltano/lib/python3.8/site-packages/click/core.py", line 1657, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/Users/aj/.local/pipx/venvs/meltano/lib/python3.8/site-packages/meltano/cli/utils.py", line 530, in invoke
    super().invoke(ctx)  # noqa: WPS608
  File "/Users/aj/.local/pipx/venvs/meltano/lib/python3.8/site-packages/click/core.py", line 1657, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/Users/aj/.local/pipx/venvs/meltano/lib/python3.8/site-packages/meltano/cli/utils.py", line 577, in invoke
    super().invoke(ctx)  # noqa: WPS608
  File "/Users/aj/.local/pipx/venvs/meltano/lib/python3.8/site-packages/click/core.py", line 1404, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/Users/aj/.local/pipx/venvs/meltano/lib/python3.8/site-packages/click/core.py", line 760, in invoke
    return __callback(*args, **kwargs)
  File "/Users/aj/.local/pipx/venvs/meltano/lib/python3.8/site-packages/click/decorators.py", line 26, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "/Users/aj/.local/pipx/venvs/meltano/lib/python3.8/site-packages/meltano/cli/schedule.py", line 131, in add
    _add_job(ctx, name, job, interval)
  File "/Users/aj/.local/pipx/venvs/meltano/lib/python3.8/site-packages/meltano/cli/schedule.py", line 76, in _add_job
    added_schedule = schedule_service.add(name, job, interval)
  File "/Users/aj/.local/pipx/venvs/meltano/lib/python3.8/site-packages/meltano/core/schedule_service.py", line 135, in add
    self.add_schedule(schedule)
  File "/Users/aj/.local/pipx/venvs/meltano/lib/python3.8/site-packages/meltano/core/schedule_service.py", line 199, in add_schedule
    raise BadCronError(schedule.interval)
meltano.core.schedule_service.BadCronError: not-legit

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/Users/aj/.local/pipx/venvs/meltano/lib/python3.8/site-packages/meltano/cli/__init__.py", line 74, in _run_cli
    raise CliError(str(err)) from err
meltano.cli.utils.CliError: not-legit
not-legit

With these updates, results are formatted nicely but the output is MUCH more verbose and harder to grok for this reason:

New Output

aj@ajs-macbook-pro deleteme-temp2 % meltano6640 --log-level=debug schedule add invalid-cron-sched --interval=not-legit --job=asdf
2022-09-02T19:07:54.243398Z [info     ] Environment 'dev' is active
2022-09-02T19:07:54.344180Z [debug    ] Creating engine <meltano.core.project.Project object at 0x108fb6580>@sqlite:////Users/aj/Source/deleteme-temp2/.meltano/meltano.db
2022-09-02T19:07:54.996152Z [debug    ] not-legit
╭─────────────────────────────── Traceback (most recent call last) ────────────────────────────────╮
│ /Users/aj/.local/pipx/venvs/meltano6640/lib/python3.8/site-packages/meltano/cli/__init__.py:66   │
│ in _run_cli                                                                                      │
│                                                                                                  │
│   63 │   """Run the Meltano CLI."""                                                              │
│   64 │   try:                                                                                    │
│   65 │   │   try:  # noqa: WPS505                                                                │
│ ❱ 66 │   │   │   cli(obj={"project": None})                                                      │
│   67 │   │   except ProjectReadonly as err:                                                      │
│   68 │   │   │   raise CliError(                                                                 │
│   69 │   │   │   │   f"The requested action could not be completed: {err}"                       │
│                                                                                                  │
│ ╭───────────── locals ──────────────╮                                                            │
│ │ cli_error = CliError('not-legit') │                                                            │
│ ╰───────────────────────────────────╯                                                            │
│                                                                                                  │
│ /Users/aj/.local/pipx/venvs/meltano6640/lib/python3.8/site-packages/click/core.py:1130 in        │
│ __call__                                                                                         │
│                                                                                                  │
│   1127 │                                                                                         │
│   1128 │   def __call__(self, *args: t.Any, **kwargs: t.Any) -> t.Any:                           │
│   1129 │   │   """Alias for :meth:`main`."""                                                     │
│ ❱ 1130 │   │   return self.main(*args, **kwargs)                                                 │
│   1131                                                                                           │
│   1132                                                                                           │
│   1133 class Command(BaseCommand):                                                               │
│                                                                                                  │
│ ╭─────────────────────────────────────────── locals ───────────────────────────────────────────╮ │
│ │   args = ()                                                                                  │ │
│ │ kwargs = {                                                                                   │ │
│ │          │   'obj': {                                                                        │ │
│ │          │   │   'project': <meltano.core.project.Project object at 0x108fb6580>,            │ │
│ │          │   │   'verbosity': 0,                                                             │ │
│ │          │   │   'is_default_environment': True,                                             │ │
│ │          │   │   'tracker': <meltano.core.tracking.tracker.Tracker object at 0x108fc7dc0>,   │ │
│ │          │   │   'schedule_service': <meltano.core.schedule_service.ScheduleService object   │ │
│ │          at 0x1090e2df0>,                                                                    │ │
│ │          │   │   'task_sets_service': <meltano.core.task_sets_service.TaskSetsService object │ │
│ │          at 0x109363fa0>                                                                     │ │
│ │          │   }                                                                               │ │
│ │          }                                                                                   │ │
│ │   self = <NoWindowsGlobbingGroup cli>                                                        │ │
│ ╰──────────────────────────────────────────────────────────────────────────────────────────────╯ │
│                                                                                                  │
│ /Users/aj/.local/pipx/venvs/meltano6640/lib/python3.8/site-packages/meltano/cli/cli.py:38 in     │
│ main                                                                                             │
│                                                                                                  │
│    35 │   │   │   args: Positional arguments for the Click group.                                │
│    36 │   │   │   kwargs: Keyword arguments for the Click group.                                 │
│    37 │   │   """                                                                                │
│ ❱  38 │   │   return super().main(*args, windows_expand_args=False, **kwargs)                    │
│    39                                                                                            │
│    40                                                                                            │
│    41 @click.group(                                                                              │
│                                                                                                  │
│ ╭─────────────────────────────────────────── locals ───────────────────────────────────────────╮ │
│ │ __class__ = <class 'meltano.cli.cli.NoWindowsGlobbingGroup'>                                 │ │
│ │      args = ()                                                                               │ │
│ │    kwargs = {                                                                                │ │
│ │             │   'obj': {                                                                     │ │
│ │             │   │   'project': <meltano.core.project.Project object at 0x108fb6580>,         │ │
│ │             │   │   'verbosity': 0,                                                          │ │
│ │             │   │   'is_default_environment': True,                                          │ │
│ │             │   │   'tracker': <meltano.core.tracking.tracker.Tracker object at              │ │
│ │             0x108fc7dc0>,                                                                    │ │
│ │             │   │   'schedule_service': <meltano.core.schedule_service.ScheduleService       │ │
│ │             object at 0x1090e2df0>,                                                          │ │
│ │             │   │   'task_sets_service': <meltano.core.task_sets_service.TaskSetsService     │ │
│ │             object at 0x109363fa0>                                                           │ │
│ │             │   }                                                                            │ │
│ │             }                                                                                │ │
│ │      self = <NoWindowsGlobbingGroup cli>                                                     │ │
│ ╰──────────────────────────────────────────────────────────────────────────────────────────────╯ │
│                                                                                                  │
│ /Users/aj/.local/pipx/venvs/meltano6640/lib/python3.8/site-packages/click/core.py:1055 in main   │
│                                                                                                  │
│   1052 │   │   try:                                                                              │
│   1053 │   │   │   try:                                                                          │
│   1054 │   │   │   │   with self.make_context(prog_name, args, **extra) as ctx:                  │
│ ❱ 1055 │   │   │   │   │   rv = self.invoke(ctx)                                                 │
│   1056 │   │   │   │   │   if not standalone_mode:                                               │
│   1057 │   │   │   │   │   │   return rv                                                         │
│   1058 │   │   │   │   │   # it's not safe to `ctx.exit(rv)` here!                               │
│                                                                                                  │
│ ╭─────────────────────────────────────────── locals ───────────────────────────────────────────╮ │
│ │                args = [                                                                      │ │
│ │                       │   'schedule',                                                        │ │
│ │                       │   'add',                                                             │ │
│ │                       │   'invalid-cron-sched',                                              │ │
│ │                       │   '--interval=not-legit',                                            │ │
│ │                       │   '--job=asdf'                                                       │ │
│ │                       ]                                                                      │ │
│ │        complete_var = None                                                                   │ │
│ │                 ctx = <click.core.Context object at 0x107bf4f70>                             │ │
│ │               extra = {                                                                      │ │
│ │                       │   'obj': {                                                           │ │
│ │                       │   │   'project': <meltano.core.project.Project object at             │ │
│ │                       0x108fb6580>,                                                          │ │
│ │                       │   │   'verbosity': 0,                                                │ │
│ │                       │   │   'is_default_environment': True,                                │ │
│ │                       │   │   'tracker': <meltano.core.tracking.tracker.Tracker object at    │ │
│ │                       0x108fc7dc0>,                                                          │ │
│ │                       │   │   'schedule_service':                                            │ │
│ │                       <meltano.core.schedule_service.ScheduleService object at 0x1090e2df0>, │ │
│ │                       │   │   'task_sets_service':                                           │ │
│ │                       <meltano.core.task_sets_service.TaskSetsService object at 0x109363fa0> │ │
│ │                       │   }                                                                  │ │
│ │                       }                                                                      │ │
│ │           prog_name = 'meltano6640'                                                          │ │
│ │                self = <NoWindowsGlobbingGroup cli>                                           │ │
│ │     standalone_mode = True                                                                   │ │
│ │ windows_expand_args = False                                                                  │ │
│ ╰──────────────────────────────────────────────────────────────────────────────────────────────╯ │
│                                                                                                  │
│ /Users/aj/.local/pipx/venvs/meltano6640/lib/python3.8/site-packages/meltano/cli/utils.py:541 in  │
│ invoke                                                                                           │
│                                                                                                  │
│   538 │   │   ctx.ensure_object(dict)                                                            │
│   539 │   │   if ctx.obj.get("tracker"):                                                         │
│   540 │   │   │   ctx.obj["tracker"].add_contexts(CliContext.from_click_context(ctx))            │
│ ❱ 541 │   │   super().invoke(ctx)  # noqa: WPS608                                                │
│   542                                                                                            │
│   543                                                                                            │
│   544 class InstrumentedCmd(click.Command):                                                      │
│                                                                                                  │
│ ╭───────────────────────── locals ──────────────────────────╮                                    │
│ │ __class__ = <class 'meltano.cli.utils.InstrumentedGroup'> │                                    │
│ │       ctx = <click.core.Context object at 0x107bf4f70>    │                                    │
│ │      self = <NoWindowsGlobbingGroup cli>                  │                                    │
│ ╰───────────────────────────────────────────────────────────╯                                    │
│                                                                                                  │
│ /Users/aj/.local/pipx/venvs/meltano6640/lib/python3.8/site-packages/click/core.py:1657 in invoke │
│                                                                                                  │
│   1654 │   │   │   │   super().invoke(ctx)                                                       │
│   1655 │   │   │   │   sub_ctx = cmd.make_context(cmd_name, args, parent=ctx)                    │
│   1656 │   │   │   │   with sub_ctx:                                                             │
│ ❱ 1657 │   │   │   │   │   return _process_result(sub_ctx.command.invoke(sub_ctx))               │
│   1658 │   │                                                                                     │
│   1659 │   │   # In chain mode we create the contexts step by step, but after the                │
│   1660 │   │   # base command has been invoked.  Because at that point we do not                 │
│                                                                                                  │
│ ╭───────────────────────────────────────── locals ─────────────────────────────────────────╮     │
│ │       __class__ = <class 'click.core.MultiCommand'>                                      │     │
│ │ _process_result = <function MultiCommand.invoke.<locals>._process_result at 0x105a63160> │     │
│ │            args = ['add', 'invalid-cron-sched', '--interval=not-legit', '--job=asdf']    │     │
│ │             cmd = <InstrumentedDefaultGroup schedule>                                    │     │
│ │        cmd_name = 'schedule'                                                             │     │
│ │             ctx = <click.core.Context object at 0x107bf4f70>                             │     │
│ │            self = <NoWindowsGlobbingGroup cli>                                           │     │
│ │         sub_ctx = <click.core.Context object at 0x105b22fd0>                             │     │
│ ╰──────────────────────────────────────────────────────────────────────────────────────────╯     │
│                                                                                                  │
│ /Users/aj/.local/pipx/venvs/meltano6640/lib/python3.8/site-packages/meltano/cli/utils.py:530 in  │
│ invoke                                                                                           │
│                                                                                                  │
│   527 │   │   ctx.ensure_object(dict)                                                            │
│   528 │   │   if ctx.obj.get("tracker"):                                                         │
│   529 │   │   │   ctx.obj["tracker"].add_contexts(CliContext.from_click_context(ctx))            │
│ ❱ 530 │   │   super().invoke(ctx)  # noqa: WPS608                                                │
│   531                                                                                            │
│   532                                                                                            │
│   533 class InstrumentedGroup(click.Group):                                                      │
│                                                                                                  │
│ ╭───────────────────────────── locals ─────────────────────────────╮                             │
│ │ __class__ = <class 'meltano.cli.utils.InstrumentedDefaultGroup'> │                             │
│ │       ctx = <click.core.Context object at 0x105b22fd0>           │                             │
│ │      self = <InstrumentedDefaultGroup schedule>                  │                             │
│ ╰──────────────────────────────────────────────────────────────────╯                             │
│                                                                                                  │
│ /Users/aj/.local/pipx/venvs/meltano6640/lib/python3.8/site-packages/click/core.py:1657 in invoke │
│                                                                                                  │
│   1654 │   │   │   │   super().invoke(ctx)                                                       │
│   1655 │   │   │   │   sub_ctx = cmd.make_context(cmd_name, args, parent=ctx)                    │
│   1656 │   │   │   │   with sub_ctx:                                                             │
│ ❱ 1657 │   │   │   │   │   return _process_result(sub_ctx.command.invoke(sub_ctx))               │
│   1658 │   │                                                                                     │
│   1659 │   │   # In chain mode we create the contexts step by step, but after the                │
│   1660 │   │   # base command has been invoked.  Because at that point we do not                 │
│                                                                                                  │
│ ╭───────────────────────────────────────── locals ─────────────────────────────────────────╮     │
│ │       __class__ = <class 'click.core.MultiCommand'>                                      │     │
│ │ _process_result = <function MultiCommand.invoke.<locals>._process_result at 0x108fdd280> │     │
│ │            args = []                                                                     │     │
│ │             cmd = <PartialInstrumentedCmd add>                                           │     │
│ │        cmd_name = 'add'                                                                  │     │
│ │             ctx = <click.core.Context object at 0x105b22fd0>                             │     │
│ │            self = <InstrumentedDefaultGroup schedule>                                    │     │
│ │         sub_ctx = <click.core.Context object at 0x1090e2dc0>                             │     │
│ ╰──────────────────────────────────────────────────────────────────────────────────────────╯     │
│                                                                                                  │
│ /Users/aj/.local/pipx/venvs/meltano6640/lib/python3.8/site-packages/meltano/cli/utils.py:577 in  │
│ invoke                                                                                           │
│                                                                                                  │
│   574 │   │   if ctx.obj.get("tracker"):                                                         │
│   575 │   │   │   ctx.obj["tracker"].add_contexts(CliContext.from_click_context(ctx))            │
│   576 │   │   │   ctx.obj["tracker"].track_command_event(CliEvent.started)                       │
│ ❱ 577 │   │   super().invoke(ctx)  # noqa: WPS608                                                │
│   578                                                                                            │
│                                                                                                  │
│ ╭──────────────────────────── locals ────────────────────────────╮                               │
│ │ __class__ = <class 'meltano.cli.utils.PartialInstrumentedCmd'> │                               │
│ │       ctx = <click.core.Context object at 0x1090e2dc0>         │                               │
│ │      self = <PartialInstrumentedCmd add>                       │                               │
│ ╰────────────────────────────────────────────────────────────────╯                               │
│                                                                                                  │
│ /Users/aj/.local/pipx/venvs/meltano6640/lib/python3.8/site-packages/click/core.py:1404 in invoke │
│                                                                                                  │
│   1401 │   │   │   echo(style(message, fg="red"), err=True)                                      │
│   1402 │   │                                                                                     │
│   1403 │   │   if self.callback is not None:                                                     │
│ ❱ 1404 │   │   │   return ctx.invoke(self.callback, **ctx.params)                                │
│   1405 │                                                                                         │
│   1406 │   def shell_complete(self, ctx: Context, incomplete: str) -> t.List["CompletionItem"]   │
│   1407 │   │   """Return a list of completions for the incomplete value. Looks                   │
│                                                                                                  │
│ ╭───────────────────── locals ──────────────────────╮                                            │
│ │  ctx = <click.core.Context object at 0x1090e2dc0> │                                            │
│ │ self = <PartialInstrumentedCmd add>               │                                            │
│ ╰───────────────────────────────────────────────────╯                                            │
│                                                                                                  │
│ /Users/aj/.local/pipx/venvs/meltano6640/lib/python3.8/site-packages/click/core.py:760 in invoke  │
│                                                                                                  │
│    757 │   │                                                                                     │
│    758 │   │   with augment_usage_errors(__self):                                                │
│    759 │   │   │   with ctx:                                                                     │
│ ❱  760 │   │   │   │   return __callback(*args, **kwargs)                                        │
│    761 │                                                                                         │
│    762 │   def forward(                                                                          │
│    763 │   │   __self, __cmd: "Command", *args: t.Any, **kwargs: t.Any  # noqa: B902             │
│                                                                                                  │
│ ╭──────────────────────────── locals ─────────────────────────────╮                              │
│ │ _Context__callback = <function add at 0x108f16040>              │                              │
│ │     _Context__self = <click.core.Context object at 0x1090e2dc0> │                              │
│ │               args = ()                                         │                              │
│ │                ctx = <click.core.Context object at 0x1090e2dc0> │                              │
│ │             kwargs = {                                          │                              │
│ │                      │   'interval': 'not-legit',               │                              │
│ │                      │   'job': 'asdf',                         │                              │
│ │                      │   'name': 'invalid-cron-sched',          │                              │
│ │                      │   'extractor': None,                     │                              │
│ │                      │   'loader': None,                        │                              │
│ │                      │   'transform': 'skip',                   │                              │
│ │                      │   'start_date': None                     │                              │
│ │                      }                                          │                              │
│ ╰─────────────────────────────────────────────────────────────────╯                              │
│                                                                                                  │
│ /Users/aj/.local/pipx/venvs/meltano6640/lib/python3.8/site-packages/click/decorators.py:26 in    │
│ new_func                                                                                         │
│                                                                                                  │
│    23 │   """                                                                                    │
│    24 │                                                                                          │
│    25 │   def new_func(*args, **kwargs):  # type: ignore                                         │
│ ❱  26 │   │   return f(get_current_context(), *args, **kwargs)                                   │
│    27 │                                                                                          │
│    28 │   return update_wrapper(t.cast(F, new_func), f)                                          │
│    29                                                                                            │
│                                                                                                  │
│ ╭────────────────── locals ──────────────────╮                                                   │
│ │   args = ()                                │                                                   │
│ │      f = <function add at 0x108f12f70>     │                                                   │
│ │ kwargs = {                                 │                                                   │
│ │          │   'interval': 'not-legit',      │                                                   │
│ │          │   'job': 'asdf',                │                                                   │
│ │          │   'name': 'invalid-cron-sched', │                                                   │
│ │          │   'extractor': None,            │                                                   │
│ │          │   'loader': None,               │                                                   │
│ │          │   'transform': 'skip',          │                                                   │
│ │          │   'start_date': None            │                                                   │
│ │          }                                 │                                                   │
│ ╰────────────────────────────────────────────╯                                                   │
│                                                                                                  │
│ /Users/aj/.local/pipx/venvs/meltano6640/lib/python3.8/site-packages/meltano/cli/schedule.py:131  │
│ in add                                                                                           │
│                                                                                                  │
│   128 │   │                                                                                      │
│   129 │   │   _add_elt(ctx, name, extractor, loader, transform, interval, start_date)            │
│   130 │   │   return                                                                             │
│ ❱ 131 │   _add_job(ctx, name, job, interval)                                                     │
│   132                                                                                            │
│   133                                                                                            │
│   134 def _format_job_list_output(entry: Schedule, job: TaskSets) -> dict:                       │
│                                                                                                  │
│ ╭──────────────────────── locals ─────────────────────────╮                                      │
│ │        ctx = <click.core.Context object at 0x1090e2dc0> │                                      │
│ │  extractor = None                                       │                                      │
│ │   interval = 'not-legit'                                │                                      │
│ │        job = 'asdf'                                     │                                      │
│ │     loader = None                                       │                                      │
│ │       name = 'invalid-cron-sched'                       │                                      │
│ │ start_date = None                                       │                                      │
│ │  transform = 'skip'                                     │                                      │
│ ╰─────────────────────────────────────────────────────────╯                                      │
│                                                                                                  │
│ /Users/aj/.local/pipx/venvs/meltano6640/lib/python3.8/site-packages/meltano/cli/schedule.py:76   │
│ in _add_job                                                                                      │
│                                                                                                  │
│    73 │   _, session_maker = project_engine(project)                                             │
│    74 │   session = session_maker()                                                              │
│    75 │   try:                                                                                   │
│ ❱  76 │   │   added_schedule = schedule_service.add(name, job, interval)                         │
│    77 │   │   click.echo(                                                                        │
│    78 │   │   │   f"Scheduled job '{added_schedule.name}' at {added_schedule.interval}"          │
│    79 │   │   )                                                                                  │
│                                                                                                  │
│ ╭─────────────────────────────────────────── locals ───────────────────────────────────────────╮ │
│ │                _ = Engine(sqlite:////Users/aj/Source/deleteme-temp2/.meltano/meltano.db)     │ │
│ │              ctx = <click.core.Context object at 0x1090e2dc0>                                │ │
│ │         interval = 'not-legit'                                                               │ │
│ │              job = 'asdf'                                                                    │ │
│ │             name = 'invalid-cron-sched'                                                      │ │
│ │          project = <meltano.core.project.Project object at 0x108fb6580>                      │ │
│ │ schedule_service = <meltano.core.schedule_service.ScheduleService object at 0x1090e2df0>     │ │
│ │          session = <sqlalchemy.orm.session.Session object at 0x1093692b0>                    │ │
│ │    session_maker = sessionmaker(class_='Session',                                            │ │
│ │                    bind=Engine(sqlite:////Users/aj/Source/deleteme-temp2/.meltano/meltano.d… │ │
│ │                    autoflush=True, autocommit=False, expire_on_commit=True)                  │ │
│ ╰──────────────────────────────────────────────────────────────────────────────────────────────╯ │
│                                                                                                  │
│ /Users/aj/.local/pipx/venvs/meltano6640/lib/python3.8/site-packages/meltano/core/schedule_servic │
│ e.py:135 in add                                                                                  │
│                                                                                                  │
│   132 │   │   │   The added schedule.                                                            │
│   133 │   │   """                                                                                │
│   134 │   │   schedule = Schedule(name=name, job=job, interval=interval, env=env)                │
│ ❱ 135 │   │   self.add_schedule(schedule)                                                        │
│   136 │   │   return schedule                                                                    │
│   137 │                                                                                          │
│   138 │   def remove(self, name) -> str:                                                         │
│                                                                                                  │
│ ╭───────────────────────────────────── locals ─────────────────────────────────────╮             │
│ │      env = {}                                                                    │             │
│ │ interval = 'not-legit'                                                           │             │
│ │      job = 'asdf'                                                                │             │
│ │     name = 'invalid-cron-sched'                                                  │             │
│ │ schedule = <meltano.core.schedule.Schedule object at 0x109363610>                │             │
│ │     self = <meltano.core.schedule_service.ScheduleService object at 0x1090e2df0> │             │
│ ╰──────────────────────────────────────────────────────────────────────────────────╯             │
│                                                                                                  │
│ /Users/aj/.local/pipx/venvs/meltano6640/lib/python3.8/site-packages/meltano/core/schedule_servic │
│ e.py:199 in add_schedule                                                                         │
│                                                                                                  │
│   196 │   │   │   and schedule.interval != "@once"                                               │
│   197 │   │   │   and not croniter.is_valid(schedule.interval)                                   │
│   198 │   │   ):                                                                                 │
│ ❱ 199 │   │   │   raise BadCronError(schedule.interval)                                          │
│   200 │   │                                                                                      │
│   201 │   │   with self.project.meltano_update() as meltano:                                     │
│   202 │   │   │   # guard if it already exists                                                   │
│                                                                                                  │
│ ╭───────────────────────────────────── locals ─────────────────────────────────────╮             │
│ │ schedule = <meltano.core.schedule.Schedule object at 0x109363610>                │             │
│ │     self = <meltano.core.schedule_service.ScheduleService object at 0x1090e2df0> │             │
│ ╰──────────────────────────────────────────────────────────────────────────────────╯             │
╰──────────────────────────────────────────────────────────────────────────────────────────────────╯
BadCronError: not-legit

The above exception was the direct cause of the following exception:

╭─────────────────────────────── Traceback (most recent call last) ────────────────────────────────╮
│ /Users/aj/.local/pipx/venvs/meltano6640/lib/python3.8/site-packages/meltano/cli/__init__.py:74   │
│ in _run_cli                                                                                      │
│                                                                                                  │
│   71 │   │   except KeyboardInterrupt:  # noqa: WPS329                                           │
│   72 │   │   │   raise                                                                           │
│   73 │   │   except Exception as err:                                                            │
│ ❱ 74 │   │   │   raise CliError(str(err)) from err                                               │
│   75 │   except CliError as cli_error:                                                           │
│   76 │   │   cli_error.print()                                                                   │
│   77 │   │   sys.exit(1)                                                                         │
│                                                                                                  │
│ ╭───────────── locals ──────────────╮                                                            │
│ │ cli_error = CliError('not-legit') │                                                            │
│ ╰───────────────────────────────────╯                                                            │
╰──────────────────────────────────────────────────────────────────────────────────────────────────╯
CliError: not-legit

not-legit

[aaronsteers]

@kgpayne - Have you done any usage tests on your side? Based on the output in my comment above, we may need to remove some frames as documented here:

https://rich.readthedocs.io/en/stable/traceback.html#suppressing-frames

Probably not by coincidence, those docs give the example of removing stracktrace detail from click and click also makes up the bulk of the output my output above. For comparison, the plain-printed output is 45 lines versus 381 lines from rich.

🥷 Edit: On reviewing the above logs, I think it makes sense to suppress frames from click, meltano.cli.cli, meltano.cli.utils, and if we can: meltano.cli.__init__.py. It may be simplest to just supress frames from click and all of meltano.cli in this iteration, and then we can continue to tune/calibrate this over time.

[aaronsteers]

@kgpayne - Exciting to see this merged! Thanks for your quick work on adding the click library suppression. 🚢 🎉