FMG API From Scratch Part 7: Stage and Inspect, or Was Anything Actually Written?
Part 6 ended with stage returning a task id. This part is about what you do next, because there are three separate questions and it is easy to answer only the first:
| Question | Where the answer is |
|---|---|
| Did the task finish, and how? | The task, at /task/task/<id> |
| What does FortiManager say it ran? | The script execution log |
| Did anything change? | The Device Database, before and after |
Only the third one matters. The first two can both say “success” while the third says nothing happened, which is exactly what the Jinja trap in Part 6 does.
The code for this part is in the fmg-api-from-scratch repo at tag part-07.
The task
exec on the script endpoint doesn’t run anything synchronously. It queues work and returns a task id, and you poll:
GET /task/task/<id>
The record has a numeric state. On my 7.6.6 box, 4 is success and 5 is failure. Those are the two terminal states I have seen; other values appear while the task runs, and I have not confirmed what they all mean, so the code treats only 4 and 5 as final.
TASK_OK, TASK_FAILED = 4, 5 # the two terminal states seen on 7.6.6; others are unconfirmed
def wait_for_task(fmg, task: int, *, timeout: float = 180, interval: float = 2,
sleep: Callable[[float], None] = time.sleep) -> dict:
"""Poll until the task reaches a terminal state; raise TimeoutError if it doesn't."""
waited = 0.0
while True:
status = task_state(fmg, task)
if status.get("state") in (TASK_OK, TASK_FAILED):
return status
if waited >= timeout:
raise TimeoutError(f"task {task} still in state {status.get('state')!r} after {timeout}s")
sleep(interval)
waited += interval
Two design points. It raises on timeout rather than returning whatever it last saw, because a caller who forgets to check would treat “still running” as an answer. And sleep is a parameter, so the tests run instantly and can prove the polling logic without waiting.
A task in state 4 means FortiManager finished what it was asked to do. It does not mean what you meant it to do was done.
The execution log
FortiManager keeps a record of every script run. The log is a plain-text transcript. A run of a small DNS script looks like this (device name and addresses replaced):
Starting log (Run on database)
config system dns
set primary 192.0.2.53
set secondary 198.51.100.53
set domain "lab.local"
end
Running script(system_dns__<device>) on DB success
Note what it contains: the CLI that was sent, after variables were substituted. That is the same secret-handling point as Part 6. If a template sets a pre-shared key, the log holds it. So the tool prints a log for a human to read on purpose (log --show), and nothing else prints or stores one.
Finding the right log
This is the part that cost me the most time, because there are several endpoints that look interchangeable and every wrong answer looked plausible. They do not cover the same things:
| Endpoint | What it actually covers |
|---|---|
/dvmdb/adom/<adom>/script/log/summary | Runs at ADOM level (policy package and ADOM database runs). It did not list my device runs at all. |
/dvmdb/adom/<adom>/script/log/latest | The newest of those ADOM-level runs. It returned log_id 181, from July. |
/dvmdb/adom/<adom>/script/log/latest/device/<device> | Supposed to be the newest run for one device. It returned log_id 801, from 1 October, when I had run scripts against that device that afternoon. |
/dvmdb/adom/<adom>/script/log/summary/device/<device> | Every run recorded for one device. This one was right. |
/dvmdb/adom/<adom>/script/log/output/device/<device>/logid/<id> | One device run in full: content, exec_time, log_id, script_name. Right. |
/dvmdb/adom/<adom>/script/log/output/logid/<id> | One run in full, but only for ADOM-level runs. For a device run it returned -3. |
The per-device summary, sorted newest first by log_id, looked like this on the day I tested it. The top entry is the run I had just made, at 15:58 that afternoon:
1271 Oct 18 15:58:13
1121
1081
1051
831
811
801 (the one latest/device kept returning)
791
501
471
So latest/device did not fail. It returned a real record. It just wasn’t the newest, and nothing in the reply says so.
Two things I believed here were wrong, and both were easy to believe. The ADOM summary is not a capped or lossy list of device runs; it answers a different question, so it never lists them. And the per-device latest endpoint, which I trusted because it returned a value for three of my four devices, returned a stale run. A value that exists is not a value that is current.
The id is the task id
The way out of guessing is that the community How-To for the FortiManager API documents how log ids are built: the log_id is the task id followed by a 1 for a run against the Device Database, or followed by a 0 for a run on the real device. I have only run the first kind.
So the run for a task is a calculation, not a search. These are my own runs:
| Stage task | Log id read back |
|---|---|
| 127 | 1271 |
| 137 | 1371 |
| 138 | 1381 |
def log_id_for_task(task: int, *, real_device: bool = False) -> int:
"""The documented rule: log_id is the task id followed by 1 for a run
against the Device Database, or 0 for a run on the real device."""
return int(f"{task}{0 if real_device else 1}")
stage waits for the task, and log --log-id 1381 reads exactly that run. With no --log-id, log takes the highest log_id from the per-device summary:
def latest_log(fmg, adom: str, device: str, log_id: int | None = None) -> dict | None:
if log_id is None:
runs = device_summary(fmg, adom, device)
if not runs:
return None
log_id = max(r["log_id"] for r in runs)
try:
return log_output(fmg, adom, device, log_id)
except FMGShapeError:
return None
Which field says “newest”?
The summary has both seq and log_id. seq looks like the natural sort key and it is not chronological: in my data, entries appeared with seq values out of order relative to their exec_time. log_id rose with execution time throughout, so it’s the one to sort on.
A control question for “OK, no data”
FortiManager answers a URL that doesn’t exist and a URL with nothing to return in the same way: status 0 and no data. At one point I concluded an endpoint didn’t exist because it came back like that, and it did exist. The test that would have caught it is to ask the same endpoint about something that must have an answer. One control question separates “no such endpoint” from “nothing to show”.
Did anything change?
Now the question that matters. The method is the one from Part 5’s rule about writes, applied to staging: read the state the operation changes, before and after.
- Read the device’s Device Database for the object the script touches, for example
/pm/config/device/<device>/global/system/dns. - Stage the script and wait for the task.
- Read the same object again.
- Compare.
The comparison reports field names and never values, because a value could be a secret:
def changed_keys(before: Any, after: Any) -> list[str]:
"""Names of the top-level fields that differ. Names only: values may be secrets."""
if not isinstance(before, dict) or not isinstance(after, dict):
return [] if before == after else ["(whole value)"]
return sorted(k for k in set(before) | set(after) if before.get(k) != after.get(k))
Then interpret the result carefully, because there are four outcomes and only one is clearly good:
| Task | Log | Fields changed | What it means |
|---|---|---|---|
| Succeeded | success | The ones the script sets | The stage worked |
| Succeeded | success | None | Either the script set what was already there, or nothing was written (the Jinja trap, or a wrong target) |
| Succeeded | success | Fields the script doesn’t mention | Something else changed the database while you were looking |
| Failed | error text | None | A normal failure, and the log says why |
The second row is the dangerous one, and it has an innocent cause: if the device already had the value, nothing changes, correctly. That is why a test stage should change something on purpose, then confirm the change, and put the value back. A test that sets a value to what it already is proves nothing.
The test on a lab device
I changed the DNS domain on one spoke from lab.local to lab.test, because it is harmless and easy to see:
$ python fmg_push.py stage --script dns__<spoke-1> --device <spoke-1> \
--watch /pm/config/device/<spoke-1>/global/system/dns --apply
Task 138 finished, state 4 (success).
Fields changed in the Device Database: domain
The log for that run was 1381, and its content was the five lines of CLI with lab.test in them. Three independent things agree: the task, the log, and the changed field. That is what a stage that worked looks like.
Staging the revert to lab.local (task 144) reported the same single field, domain, changing back.
A second record: FortiManager’s own Event Log
The Event Log in the GUI recorded these runs too. The entries are for the API account, show the source address of the jumpbox, and show the old value in brackets next to the new one:
type=sys_dns,domain=lab.local(lab.test) userfrom=JSON(192.0.2.6)
That is useful as an independent cross-check, because it was written by FortiManager and not by my tool. It was there even though I have the JSON API logging setting disabled. That setting has request and response modes that capture what the client sent, and I leave it off because a request mode would capture the login credentials.
The GUI’s “Modified” is not the install diff
One thing that misled me during this: after staging, the device’s Config Status in the GUI said Modified, but the Install Preview showed nothing to install. They are measuring different things. The status comes from the Device Database compared with the last saved revision; the preview compares the Device Database with the device. In my case the Device Database and the device agreed, so there was nothing to preview, yet the database differed from its last saved revision, so the status said Modified.
What cleared it was Retrieve Config from the device’s revision history in the GUI. It pulls the configuration from the device, saves a new revision and pushes nothing. The status went to Synchronized. If your device shows Modified and an empty preview, check the diff before assuming something is pending.
The tests
The tests cover the reasoning above, not just the happy path:
- Polling continues through non-terminal states and stops at 4 or 5.
- A failed task is terminal and is not counted as success.
- A task that never finishes raises
TimeoutErrorinstead of hanging. - The log id is the task id followed by 1, or 0 for a real-device run.
- The newest run is the highest
log_id, not the first entry and not the highestseq. latest_lognever calls thelatestendpoints.- A device with no recorded runs gives
None. - The change check reports field names and never the values that changed.
Checklist
- A finished task is not a result. Read the state before and after
- Poll the task with a timeout that raises, and treat only confirmed terminal states as final
- Read the log by the id the task gives you: the task id followed by 1
- Use the per-device summary and the per-device output. The
latestendpoints returned stale runs on my box - A value that exists is not a value that is current
- “OK, no data” is ambiguous. Ask the same endpoint about something that must have an answer
- Sort log entries by
log_id, neverseq - A test stage must change something on purpose, or it proves nothing
- Compare field names, not values
- Logs contain the rendered CLI, secrets included
- The GUI’s Modified status is not the install diff
What comes next
Staging has changed the Device Database and nothing else. Part 8 is the step that reaches the live unit: install, which is a preview followed by a commit, using numeric IDs, and which is where the permission mistakes in Part 4 came from.