canonical / charms.reactive

Framework for developing charms and relations using the reactive pattern
Apache License 2.0
22 stars 34 forks source link

CLI charms.reactive set_flag acts differently to set_flag call from a reactive script #230

Closed auria closed 3 years ago

auria commented 3 years ago

When I use set_flag from a reactive script, the created state will be persistent after Juju hooks are run. However, if I run charms.reactive set_flag <state> via juju run -u unit/N, the update-status hook will finish clearing the created state.

Please find below how I reproduced it:

$ juju status
Model  Controller  Cloud/Region         Version  SLA          Timestamp
test   lxd         localhost/localhost  2.8.7    unsupported  11:46:54Z

App        Version  Status   Scale  Charm      Store  Rev  OS      Notes
testflags           unknown      1  testflags  local    2  ubuntu  

Unit          Workload  Agent  Machine  Public address  Ports  Message
testflags/0*  unknown   idle   0        10.0.8.180             

Machine  State    DNS         Inst id        Series  AZ  Message
0        started  10.0.8.180  juju-aca342-0  bionic      Running
from charmhelpers.core import hookenv

from charms.reactive import is_flag_set, when_not

@hookenv.atexit
def assess_status():
    message = "All good."
    if not is_flag_set("certificates.available"):
        message = "Missing relations: certificates"
    hookenv.log("Assess status => {}".format(message))

layer.yaml content:

$ cat testflags/layer.yaml 
"includes":
- "layer:options"
- "layer:basic"
- "interface:tls-certificates"
"exclude": [".travis.yml", "tests", "tox.ini", "test-requirements.txt", "unit_tests",
  ".gitignore", ".gitreview", ".zuul.yaml", "README.md", "requirements.txt"]
"options":
  "basic":
    "packages": []
    "python_packages": []
    "use_venv": !!bool "true"
    "include_system_packages": !!bool "false"
  "testflags": {}
"is": "testflags"

Once the test application is deployed, I run an initial test:

$ juju run -u testflags/0 hooks/update-status
$ juju debug-log
unit-testflags-0: 11:48:22 DEBUG juju.worker.uniter.remotestate got action change for testflags/0: [48] ok=true
unit-testflags-0: 11:48:22 DEBUG juju.worker.uniter.operation running operation run action 48 for testflags/0
unit-testflags-0: 11:48:22 DEBUG juju.machinelock acquire machine lock for testflags/0 uniter (run action 48)
unit-testflags-0: 11:48:22 DEBUG juju.machinelock machine lock acquired for testflags/0 uniter (run action 48)
unit-testflags-0: 11:48:22 DEBUG juju.worker.uniter.operation preparing operation "run action 48" for testflags/0
unit-testflags-0: 11:48:22 DEBUG juju.worker.uniter.operation executing operation "run action 48" for testflags/0
unit-testflags-0: 11:48:22 DEBUG juju.worker.uniter [AGENT-STATUS] executing: running action juju-run
unit-testflags-0: 11:48:22 DEBUG juju.worker.uniter.runner juju-run action is running
unit-testflags-0: 11:48:22 DEBUG juju.worker.uniter.runner starting jujuc server  {unix @/var/lib/juju/agents/unit-testflags-0/agent.socket <nil>}
unit-testflags-0: 11:48:23 DEBUG jujuc running hook tool "juju-log" for testflags/0-juju-run-6422856325876939239
unit-testflags-0: 11:48:23 INFO unit.testflags/0.juju-log Reactive main running for hook
unit-testflags-0: 11:48:23 DEBUG jujuc running hook tool "config-get" for testflags/0-juju-run-6422856325876939239
unit-testflags-0: 11:48:23 DEBUG jujuc running hook tool "relation-ids" for testflags/0-juju-run-6422856325876939239
unit-testflags-0: 11:48:23 DEBUG jujuc running hook tool "juju-log" for testflags/0-juju-run-6422856325876939239
unit-testflags-0: 11:48:23 DEBUG unit.testflags/0.juju-log tracer: starting handler dispatch, 0 flags set
unit-testflags-0: 11:48:23 DEBUG jujuc running hook tool "juju-log" for testflags/0-juju-run-6422856325876939239
unit-testflags-0: 11:48:23 DEBUG unit.testflags/0.juju-log tracer: hooks phase, 0 handlers queued
unit-testflags-0: 11:48:23 DEBUG jujuc running hook tool "juju-log" for testflags/0-juju-run-6422856325876939239
unit-testflags-0: 11:48:23 DEBUG unit.testflags/0.juju-log tracer>
tracer: main dispatch loop, 1 handlers queued
tracer: ++   queue handler hooks/relations/tls-certificates/requires.py:109:broken:certificates
unit-testflags-0: 11:48:23 DEBUG jujuc running hook tool "juju-log" for testflags/0-juju-run-6422856325876939239
unit-testflags-0: 11:48:23 INFO unit.testflags/0.juju-log Invoking reactive handler: hooks/relations/tls-certificates/requires.py:109:broken:certificates
unit-testflags-0: 11:48:23 DEBUG jujuc running hook tool "juju-log" for testflags/0-juju-run-6422856325876939239
unit-testflags-0: 11:48:23 INFO unit.testflags/0.juju-log Assess status => Missing relations: certificates
unit-testflags-0: 11:48:23 DEBUG juju.worker.uniter.operation committing operation "run action 48" for testflags/0
unit-testflags-0: 11:48:23 DEBUG juju.machinelock machine lock released for testflags/0 uniter (run action 48)
unit-testflags-0: 11:48:23 DEBUG juju.worker.uniter.operation lock released for testflags/0
unit-testflags-0: 11:48:23 DEBUG juju.worker.uniter no operations in progress; waiting for changes
unit-testflags-0: 11:48:23 DEBUG juju.worker.uniter [AGENT-STATUS] idle:
root@juju-aca342-0:/var/lib/juju/agents/unit-testflags-0/charm# sqlite3 .unit-state.db 
SQLite version 3.22.0 2018-01-22 18:45:57
Enter ".help" for usage hints.
sqlite> select * from kv;
reactive.dispatch.removed_state|true
reactive.dispatch.phase|"other"

sqlite> select * from kv; reactive.dispatch.removed_state|true reactive.dispatch.phase|"other" reactive.states.certificates.available|null reactive.state_watch|{"iteration": 0, "changes": [], "pending": ["certificates.available"]}


* Run `update-status`:

$ juju run -u testflags/0 hooks/update-status $ juju debug-log unit-testflags-0: 11:54:23 DEBUG juju.worker.uniter.remotestate got action change for testflags/0: [56] ok=true unit-testflags-0: 11:54:23 DEBUG juju.worker.uniter.operation running operation run action 56 for testflags/0 unit-testflags-0: 11:54:23 DEBUG juju.machinelock acquire machine lock for testflags/0 uniter (run action 56) unit-testflags-0: 11:54:23 DEBUG juju.machinelock machine lock acquired for testflags/0 uniter (run action 56) unit-testflags-0: 11:54:23 DEBUG juju.worker.uniter.operation preparing operation "run action 56" for testflags/0 unit-testflags-0: 11:54:23 DEBUG juju.worker.uniter.operation executing operation "run action 56" for testflags/0 unit-testflags-0: 11:54:23 DEBUG juju.worker.uniter [AGENT-STATUS] executing: running action juju-run unit-testflags-0: 11:54:23 DEBUG juju.worker.uniter.runner juju-run action is running unit-testflags-0: 11:54:23 DEBUG juju.worker.uniter.runner starting jujuc server {unix @/var/lib/juju/agents/unit-testflags-0/agent.socket } unit-testflags-0: 11:54:23 DEBUG jujuc running hook tool "juju-log" for testflags/0-juju-run-3865382029819934043 unit-testflags-0: 11:54:23 INFO unit.testflags/0.juju-log Reactive main running for hook unit-testflags-0: 11:54:23 DEBUG jujuc running hook tool "config-get" for testflags/0-juju-run-3865382029819934043 unit-testflags-0: 11:54:23 DEBUG jujuc running hook tool "relation-ids" for testflags/0-juju-run-3865382029819934043 unit-testflags-0: 11:54:23 DEBUG jujuc running hook tool "juju-log" for testflags/0-juju-run-3865382029819934043 unit-testflags-0: 11:54:23 DEBUG unit.testflags/0.juju-log tracer> tracer: starting handler dispatch, 1 flags set tracer: set flag certificates.available unit-testflags-0: 11:54:23 DEBUG jujuc running hook tool "juju-log" for testflags/0-juju-run-3865382029819934043 unit-testflags-0: 11:54:23 DEBUG unit.testflags/0.juju-log tracer: hooks phase, 0 handlers queued unit-testflags-0: 11:54:23 DEBUG jujuc running hook tool "juju-log" for testflags/0-juju-run-3865382029819934043 unit-testflags-0: 11:54:23 DEBUG unit.testflags/0.juju-log tracer> tracer: main dispatch loop, 1 handlers queued tracer: ++ queue handler hooks/relations/tls-certificates/requires.py:109:broken:certificates unit-testflags-0: 11:54:23 DEBUG jujuc running hook tool "juju-log" for testflags/0-juju-run-3865382029819934043 unit-testflags-0: 11:54:23 INFO unit.testflags/0.juju-log Invoking reactive handler: hooks/relations/tls-certificates/requires.py:109:broken:certificates unit-testflags-0: 11:54:23 DEBUG jujuc running hook tool "juju-log" for testflags/0-juju-run-3865382029819934043 unit-testflags-0: 11:54:23 DEBUG unit.testflags/0.juju-log tracer: cleared flag certificates.available unit-testflags-0: 11:54:23 DEBUG jujuc running hook tool "juju-log" for testflags/0-juju-run-3865382029819934043 unit-testflags-0: 11:54:23 INFO unit.testflags/0.juju-log Assess status => Missing relations: certificates unit-testflags-0: 11:54:23 DEBUG juju.worker.uniter.operation committing operation "run action 56" for testflags/0 unit-testflags-0: 11:54:23 DEBUG juju.machinelock machine lock released for testflags/0 uniter (run action 56) unit-testflags-0: 11:54:23 DEBUG juju.worker.uniter.operation lock released for testflags/0 unit-testflags-0: 11:54:23 DEBUG juju.worker.uniter no operations in progress; waiting for changes unit-testflags-0: 11:54:23 DEBUG juju.worker.uniter [AGENT-STATUS] idle:


* Verify flags after `update-status` has been run (I expected that `certificates.available` would still be set):

$ juju run -u testflags/0 -- charms.reactive get_flags $

sqlite> select * from kv; reactive.dispatch.removed_state|true reactive.dispatch.phase|"other"



If I run the same test but creating a handler in the reactive script where `@when_not("certificates.available")`, then it sets such flag... said flag will remain persistent on the DB and when listed via `get_flags`.
johnsca commented 3 years ago

Actually, this is expected behavior because the tls-certificates interface layer manages that flag, setting it when the relation is joined and clearing it when the relation is not joined. If you try with a different flag which is not managed by the code, you should see the behavior you expect.