should actions leak deprecation warnings?

[PietroPasotti]

In my view, juju actions are the public facade of the charm. The user-facing API.
A user doesn't necessarily want to see things such as internal deprecation warnings or other logs as part of the action output, or they might think something went wrong when running the action.

I'm not sure if this is a juju or an ops concern, but this user experience should be improved:

What do you think is the way forward on this? Silence all stdout when running an action? This warning will show up in the juju debug-log anyway, which is the only place I'd expect to see it.

[benhoyt]

Yeah, I agree these shouldn't end up in the actions output. Hopefully there's a straight-forward way to make these warnings only go to the debug log. We'll aim to look into this at some point soon.

[tonyandrewmeyer]

Odd, these shouldn't end up being output, because the default filter ignores DeprecationWarning except for code in __main__.

I tested this with this little charm:

import ops
import ops.main

class ActionwarningCharm(ops.CharmBase):
    def __init__(self, framework: ops.Framework):
        super().__init__(framework)
        framework.observe(self.on.go_action, self._on_go)

    def _on_go(self, event):
        event.log("Running...")
        event.set_results({"result": "done"})

if __name__ == "__main__":
    ops.main.main(ActionwarningCharm)

And when running the action, I don't get the warning. It is being produced: if I put PYTHONWARNINGS="error::DeprecationWarning" into the dispatch script then I correctly get an error.

@PietroPasotti would any of the code be setting PYTHONWARNINGS or running the script with a -W argument or calling warnings.filterwarnings?

It seems like the correct fix is to to set the filters appropriately, but that's not going to help if something is changing them. If that isn't going to work, then we might have to use a custom showwarning that redirects to logging/debug-log rather than relying on stderr output (as we investigated and rejected previously).

[PietroPasotti]

huh no the charm is vanilla, no strange envvars set

[tonyandrewmeyer]

I don't get this with machine (Juju 3.6) or K8s (Juju 3.5.2). I also tried with the grafana[-k8s] charm (from Charmhub) and also don't get it:

$ juju run grafana-k8s/0 get-admin-password
Running operation 36 with 1 task
  - task 37 on unit-grafana-k8s-0

Waiting for task 37...
admin-password: XtVc0Zecck8y
url: http://grafana-k8s-0.grafana-k8s-endpoints.k8s-tut.svc.cluster.local:3000

$ juju run grafana/0 get-admin-password
Running operation 3 with 1 task
  - task 4 on unit-grafana-0

Waiting for task 4...
password: fnPtRCV6gHSbzq4t

Although maybe that's not built with a recent enough ops or has some other workaround...

[tonyandrewmeyer]

Ah, but latest/edge does:

$ juju run grafana-k8s/0 get-admin-password
Running operation 39 with 1 task
  - task 40 on unit-grafana-k8s-0

Waiting for task 40...
admin-password: V14gOylJ3SMc
url: http://grafana-k8s-0.grafana-k8s-endpoints.k8s-tut.svc.cluster.local:3000

./src/charm.py:1593: DeprecationWarning: Calling `ops.main.main()` is deprecated, call `ops.main()` instead
  main(GrafanaCharm, use_juju_for_storage=True)

[tonyandrewmeyer]

I can reproduce with my simple charm above when doing from ops import main ... main(MyCharm).

The issue is the stack level. When using ops.main.main() the stack is:

  File "/var/lib/juju/agents/unit-actionwarning-1/charm/./src/charm.py", line 35, in <module>
    ops.main.main(ActionwarningCharm)
  File "/var/lib/juju/agents/unit-actionwarning-1/charm/venv/ops/__init__.py", line 348, in main
    return _legacy_main.main(
  File "/var/lib/juju/agents/unit-actionwarning-1/charm/venv/ops/main.py", line 41, in main
    traceback.print_stack()

When using `from ops import main ... main(MyCharm) the stack is:

  File "/var/lib/juju/agents/unit-actionwarning-1/charm/./src/charm.py", line 34, in <module>
    main(ActionwarningCharm)
  File "/var/lib/juju/agents/unit-actionwarning-1/charm/venv/ops/main.py", line 41, in main
    traceback.print_stack()

We use a stack_level=2 argument when emitting the warning, so with the former we're still inside the code (the stack_level would more correctly be 3), but with the latter we're not, so it's effectively at __main__ which means the __main__ filter (default action) applies.

We could definitely adjust the warning filters to handle this - matching the message, for example. However, we do want the warning to be generated when people are running tests. We could blame code lower down the stack, but that's less clear to developers who need to update their code.

I feel like relying on the warnings-go-to-stdout behaviour combined with the way that action output is sent is probably the real problem here, and we should switch over to the alternative (that we'd already developed anyway).