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

When a snap fails to restart for some reason, e.g. "Start request repeated too quickly", log messages do not reflect the reason #136

Open
sed-i opened this issue Nov 14, 2024 · 1 comment

Comments

@sed-i
Copy link

sed-i commented Nov 14, 2024

Problem 1: set fails because charm is restarted to quickly

I need to call snap.set immediately after start/ensure, like so:

    if snap.present:
        if snap.revision != revision:
            cmd = ["snap", "refresh", "grafana-agent", f'--revision="{revision}"']
            if classic:
                cmd.append("--classic")
            subprocess.run(cmd)
            snap.start(enable=True)
    else:
        snap.ensure(state=snap_lib.SnapState.Present, revision=revision, classic=classic)

    if config:
        snap.set(config)

    snap.hold()

At this point the call to snap.set fails with:

Nov 14 19:57:03 juju-c56ce2-18 systemd[1]: snap.grafana-agent.grafana-agent.service: Scheduled restart job, restart counter is at 5.
Nov 14 19:57:03 juju-c56ce2-18 systemd[1]: Stopped Service for snap application grafana-agent.grafana-agent.
Nov 14 19:57:03 juju-c56ce2-18 systemd[1]: snap.grafana-agent.grafana-agent.service: Start request repeated too quickly.
Nov 14 19:57:03 juju-c56ce2-18 systemd[1]: snap.grafana-agent.grafana-agent.service: Failed with result 'exit-code'.
Nov 14 19:57:03 juju-c56ce2-18 systemd[1]: Failed to start Service for snap application grafana-agent.grafana-agent.
Nov 14 19:57:09 juju-c56ce2-18 systemd[1]: snap.grafana-agent.grafana-agent.service: Start request repeated too quickly.
Nov 14 19:57:09 juju-c56ce2-18 systemd[1]: snap.grafana-agent.grafana-agent.service: Failed with result 'exit-code'.
Nov 14 19:57:09 juju-c56ce2-18 systemd[1]: Failed to start Service for snap application grafana-agent.grafana-agent.

Problem 2a: the log message doesn't show stderr

In the traceback I see messages such as

charms.operator_libs_linux.v2.snap.SnapError: Snap: 'grafana-agent'; command ['snap', 'set', 'grafana-agent', 'reporting-enabled=1'] failed with output = ''

because SnapError doesn't print e.stderr. Perhaps it would be handy to also include e.stderr here:

raise SnapError(
"Snap: {!r}; command {!r} failed with output = {!r}".format(
self._name, args, e.output
)

Problem 2b: this error doesn't go to stderr anyway, so pull from journalctl or systemctl?

I manually added stderr to the log but discovered there's nothing there, all the errors are logged to journal. Should the lib pull from the journal when raising SnapError?

@sed-i
Copy link
Author

sed-i commented Nov 14, 2024

Note: the rapid restart is due to an error I discovered with snap logs, due to a build error: canonical/grafana-agent-snap#80.

So there is no problem with snap.set, the only problem is that the reason for restart failure is buried.

@sed-i sed-i changed the title The snap lib fails to apply config due to "Start request repeated too quickly" When a snap fails to restart for some reason, e.g. "Start request repeated too quickly", log messages do not reflect the reason Nov 14, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant