Charm did not get any events between stop and start

Bug #2015566 reported by Leon
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Canonical Juju
Triaged
Undecided
Unassigned

Bug Description

While running a load test for COS Lite, a workloadless charm received a StopContainer (haven't figured out why yet).

As a result, a `stop` hook was followed by a `start` hook with nothing in between and nothing after.

$ juju debug-log -i unit-scrape-target-0 --replay | grep Emitting
unit-scrape-target-0: 06:56:26 DEBUG unit.scrape-target/0.juju-log Emitting Juju event update_status.
unit-scrape-target-0: 07:00:37 DEBUG unit.scrape-target/0.juju-log Emitting Juju event stop.
unit-scrape-target-0: 07:00:44 DEBUG unit.scrape-target/0.juju-log Emitting Juju event start.
unit-scrape-target-0: 07:05:36 DEBUG unit.scrape-target/0.juju-log Emitting Juju event update_status.
unit-scrape-target-0: 07:09:56 DEBUG unit.scrape-target/0.juju-log Emitting Juju event update_status.

$ juju show-status-log scrape-target/0
Time Type Status Message
06 Apr 2023 11:55:41-04:00 juju-unit allocating
06 Apr 2023 11:55:41-04:00 workload waiting installing agent
06 Apr 2023 11:56:26-04:00 workload waiting agent initializing
06 Apr 2023 11:56:30-04:00 workload maintenance installing charm software
06 Apr 2023 11:56:30-04:00 juju-unit executing running install hook
06 Apr 2023 11:56:32-04:00 juju-unit executing running metrics-endpoint-relation-created hook
06 Apr 2023 11:56:34-04:00 juju-unit executing running leader-elected hook
06 Apr 2023 11:56:34-04:00 juju-unit executing running config-changed hook
06 Apr 2023 11:56:36-04:00 juju-unit executing running start hook
06 Apr 2023 11:56:37-04:00 juju-unit executing running metrics-endpoint-relation-joined hook for scrape-config/0
06 Apr 2023 11:56:38-04:00 juju-unit executing running metrics-endpoint-relation-changed hook for scrape-config/0
06 Apr 2023 11:57:16-04:00 juju-unit idle
06 Apr 2023 11:57:16-04:00 workload active
07 Apr 2023 07:00:36-04:00 workload maintenance stopping charm software
07 Apr 2023 07:00:36-04:00 juju-unit executing running stop hook
07 Apr 2023 07:00:43-04:00 juju-unit executing running start hook
07 Apr 2023 07:01:27-04:00 juju-unit idle
07 Apr 2023 07:01:27-04:00 workload maintenance

In contrast, when I kubectl delete the pod, I see the full upgrade sequence:

unit-scrape-target-0: 10:40:11 DEBUG unit.scrape-target/0.juju-log Emitting Juju event stop.
unit-scrape-target-0: 10:40:19 DEBUG unit.scrape-target/0.juju-log Emitting Juju event upgrade_charm.
unit-scrape-target-0: 10:40:19 DEBUG unit.scrape-target/0.juju-log Emitting Juju event config_changed.
unit-scrape-target-0: 10:40:20 DEBUG unit.scrape-target/0.juju-log Emitting Juju event start.

Leon (sed-i)
description: updated
Revision history for this message
Leon (sed-i) wrote :

I noticed that a similar thing happened with a regular sidecar charm (grafana):
After StopContainer I only get pebble-ready:

$ juju debug-log -i unit-grafana-0 --replay | grep Emitting | grep -v "update_status"
unit-grafana-0: 23:00:45 DEBUG unit.grafana/0.juju-log Emitting Juju event litestream_pebble_ready.
unit-grafana-0: 07:00:42 DEBUG unit.grafana/0.juju-log Emitting Juju event grafana_pebble_ready.
unit-grafana-0: 07:00:52 DEBUG unit.grafana/0.juju-log Emitting Juju event litestream_pebble_ready.
unit-grafana-0: 07:03:14 DEBUG unit.grafana/0.juju-log Emitting Juju event grafana_pebble_ready.
unit-grafana-0: 07:03:23 DEBUG unit.grafana/0.juju-log Emitting Juju event litestream_pebble_ready.

Revision history for this message
Harry Pidcock (hpidcock) wrote :

Interesting, does the pod have a non-zero restart count?

Revision history for this message
Leon (sed-i) wrote :

Correct. Only the charm-init has a restart count of 0.

Revision history for this message
Leon (sed-i) wrote :

Another variant: after StopContainer (still haven't figured why this happens), I get only pebble-ready:

$ juju debug-log -i unit-grafana-0 --replay | grep Emitting | grep "pebble_ready" -C2

unit-grafana-0: 18:56:37 DEBUG unit.grafana/0.juju-log Emitting Juju event update_status.
unit-grafana-0: 19:01:20 DEBUG unit.grafana/0.juju-log Emitting Juju event update_status.
unit-grafana-0: 19:01:31 DEBUG unit.grafana/0.juju-log Emitting Juju event grafana_pebble_ready.
unit-grafana-0: 19:05:24 DEBUG unit.grafana/0.juju-log Emitting Juju event update_status.
unit-grafana-0: 19:10:29 DEBUG unit.grafana/0.juju-log Emitting Juju event update_status.

summary: - Workloadless charm did not get any events between stop and start
+ Charm did not get any events between stop and start
Changed in juju:
status: New → Triaged
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.