Skip to main content
RunBook Academy

← All break/fix scenarios in Ansible

intermediateidempotency~30 min

Break/Fix: the same task reports changed every night and the config file has 214 copies of one line

Reported symptoms

  • ●One task reports `changed` on every host on every run, and has done since the role was written
  • ●The nightly converge has never reported `changed=0` on any host
  • ●The service is restarted every night at 02:10 by a handler nobody meant to fire
  • ●`/etc/rsyslog.d/50-forward.conf` on a long-lived host is 214 lines long and contains the same forwarding rule 214 times
  • ●Newly built hosts look correct for the first day or two, which is why the file was never suspected
  • ●A `--check` run also reports `changed`, so the dry run agrees with the real run and neither is right

Evidence

  • · `ansible-playbook site.yml --check --diff --limit <host>` shows the line being added again, below the copies already present
  • · `wc -l /etc/rsyslog.d/50-forward.conf` returns a number that grows by one per converge
  • · `grep -c "^\\*\\.\\* @@logs" /etc/rsyslog.d/50-forward.conf` returns the same growing number
  • · The task in the role uses `regexp` with a leading `^` while the `line` it writes begins with whitespace
  • · `ansible-playbook ... --diff` on a freshly built host shows one insertion and looks entirely reasonable
  • · The run summary has always shown `changed=1` for this task; nothing has ever alerted, because nothing failed
  • · The handler `restart rsyslog` appears in every night of `journalctl -u rsyslog` for the last eight months
Diagnosis and resolutionclick to reveal

Root cause

The `lineinfile` task writes a line that its own `regexp` does not match. For `state: present`, `lineinfile` searches every line for the regular expression, replaces the last match if there is one, and - when there is no match - appends the line. The regexp is anchored with `^` at the start of the line, but the `line` value was later indented to match the surrounding file style, so what gets written begins with two spaces and can never match an anchored pattern again. Each run therefore finds no match, appends a fresh copy, and correctly reports `changed`. The report is accurate: the task did change the file. What is wrong is that the task cannot reach a steady state, and nothing in Ansible detects that, because "did this run change something" and "should this run have changed something" are different questions and only the first one is answered. The daily handler restart is a consequence rather than a second fault: an inaccurate `changed` notifies the handler on every run, so the restart stopped being a signal that anything happened.

Remediation

Fix the task so the pattern matches what the task writes, and prefer a mechanism that cannot drift apart: for a whole managed file, `template` with the entire content is the right tool, and `lineinfile` should be reserved for a line inside a file somebody else owns. Then clean up what accumulated - the duplicate lines are not merely untidy, since a forwarding rule repeated 214 times is 214 copies of every log message. Deduplicate with a controlled, backed-up edit rather than an ad-hoc `sed`, verify the service parses the result before restarting anything, and only then restart. Fix the role first and the hosts second, so the next converge does not immediately reinstate the duplicates.

Verification

The decisive check is a second run: converge once, then converge again with no other change, and require `changed=0` on the second. A single run reporting `changed` proves nothing either way; only the second run distinguishes a task that did work from a task that cannot stop doing work. Confirm the file is one line rather than many with `grep -c` for the rule, which must return exactly 1. Confirm the handler did not fire on the second run by reading the run output, and confirm from `journalctl -u rsyslog` that no restart occurred. Prove the check can fail by deliberately removing the line on a test host and confirming the next converge reports `changed=1` and then `changed=0`.

Prevention

Make the second run part of the definition of done. A task that has never been run twice against the same host has not been shown to be idempotent, and the second run is the only test that shows it. Gate it in CI, where a converge-converge cycle with a required `changed=0` on the second pass is cheap and catches this whole class before it ships. Alert on persistent `changed` in production, not only on failures - a host that never reaches `changed=0` is drifting or fighting itself, and the current dashboard cannot tell you which. Prefer `template` for files you own, so the file is described once and compared as a whole. When `lineinfile` is genuinely right, write the regexp against the exact string the task writes, and remember that `--check` reports the same wrong answer as a real run, so a dry run cannot catch this.

Reported symptoms

A capacity review of the central log platform finds that one application tier is sending roughly two hundred times more log volume than any comparable tier. The application has not changed.

Pulling the thread produces a second observation nobody had connected to it: the nightly Ansible converge restarts rsyslog on those hosts every single night at 02:10. It always has.

And a third: that converge has never once reported changed=0.

Nobody raised any of this because nothing ever failed. The dashboard counts failed hosts, the number has been zero for eight months, and a green run at 02:15 is not something anybody investigates.

Evidence provided

Read-only / Safeone rule, 214 lines
$ ansible app012 -i inventory -m ansible.builtin.command -a 'wc -l /etc/rsyslog.d/50-forward.conf'
214 /etc/rsyslog.d/50-forward.conf
Read-only / Safenote where the line begins
$ ansible app012 -i inventory -m ansible.builtin.command -a 'tail -3 /etc/rsyslog.d/50-forward.conf'
  *.* @@logs.example.com:6514
*.* @@logs.example.com:6514
*.* @@logs.example.com:6514
Read-only / Safethe dry run predicts exactly what the real run does - and both are wrong
$ ansible-playbook -i inventory site.yml --limit app012 --check --diff --tags logging
TASK [logging : Forward syslog to the central collector] ***********************
--- before: /etc/rsyslog.d/50-forward.conf (content)
+++ after: /etc/rsyslog.d/50-forward.conf (content)
@@ -212,3 +212,4 @@
 *.* @@logs.example.com:6514
 *.* @@logs.example.com:6514
 *.* @@logs.example.com:6514
+  *.* @@logs.example.com:6514

changed: [app012]
Read-only / Safethe task
$ grep -n -A6 'Forward syslog' roles/logging/tasks/main.yml
12:- name: Forward syslog to the central collector
13:  ansible.builtin.lineinfile:
14:    path: /etc/rsyslog.d/50-forward.conf
15:    regexp: '^\*\.\* @@logs\.example\.com'
16:    line: '  *.* @@logs.example.com:6514'
17:    create: true
18:  notify: restart rsyslog
Read-only / Safeone restart per night, for as long as the journal goes back
$ ansible app012 -i inventory -m ansible.builtin.command -a 'journalctl -u rsyslog --since -7d | grep -c Stopped'
7

Work the evidence before reading on

Everything here is behaving correctly and reporting honestly. The task changed the file, so it said changed. The handler was notified, so it ran. The dry run predicted the change, so it printed it.

  1. Read regexp and line character by character, starting at the first character of each. What does ^ anchor to, and what is the first character of the string being written?
  2. If the pattern never matches, what does lineinfile do with state: present?
  3. --check agreed with the real run. Given that, what could a dry run possibly have told you?

Before continuing: what is the smallest run you could perform that would distinguish “this task did work” from “this task cannot stop working”?

Root cause

1. The pattern cannot match the line the task writes

For state: present, lineinfile behaves in two stages. It searches every line of the file for regexp; if it finds a match it replaces the last matching line with line, and if it finds none it inserts line. There is no third case, and no complaint.

The pattern is anchored:

^\*\.\* @@logs\.example\.com

The line begins with two spaces:

  *.* @@logs.example.com:6514

^ anchors at the start of the line, so an anchored pattern cannot match a line that starts with whitespace. The task searches, fails, appends, and reports changed - accurately.

The indentation was added in a tidy-up commit six days after the role was written, to make the file match the surrounding style. The regexp was not touched, because from the diff there was no reason to touch it.

2. changed is a statement about the run, not about correctness

Ansible’s changed means “this task modified the target”. It does not mean “this task needed to”. Nothing in the model can tell the difference, because the module reports what it did and the engine believes it.

A task that appends a duplicate every run reports changed every run, truthfully, forever. The converge never converges, and the only visible trace is a number in a summary line that nobody reads when the failure count is zero.

3. The handler restart is downstream of the same fault

notify: restart rsyslog fires when the task reports changed. Since the task reports changed every night, the handler runs every night.

The service restart is not a separate bug. It is what an inaccurate changed does to everything built on top of it: the handler mechanism is only as good as the change detection feeding it, and once a restart happens every night it stops carrying any information about whether something happened.

Resolution

  1. Stop the nightly restart before anything else. Disable the schedule, or add a temporary condition, so the fleet stops accumulating another copy while you work.
  2. Fix the role, not the hosts. The pattern must match what the task writes. The better fix is to stop using lineinfile for a file that Ansible owns entirely: replace it with template rendering the whole file, so content and comparison come from one source.
  3. Measure the damage before cleaning it up. Record the line count per host, because the duplicate forwarding rules mean each host has been sending every message once per copy, and the log platform team needs that number.
  4. Clean up with a backup and a validation, not with an in-place sed. Render the corrected file to a new path, confirm the service accepts it with rsyslogd -N1 -f <path>, then move it into place.
  5. Restart the service once, deliberately, and confirm forwarding still works from the collector side rather than from the absence of errors on the host.
  6. Converge twice on one host and require changed=0 on the second run before touching the rest of the fleet.
  7. Roll out, then re-run the two-converge check on a random sample across roles and build ages, including at least one host built this week and one built a year ago.
  8. Add the converge-converge gate to CI in the same change, so the class is closed rather than this instance.

Verification

  1. The second converge reports no change. Run the play twice against the same host with nothing else altered; the second run must report changed=0 for the whole play. This is the only check that distinguishes a task that did work from a task that cannot stop.
  2. The rule appears once. grep -c "logs.example.com" /etc/rsyslog.d/50-forward.conf returns exactly 1 on every repaired host.
  3. The handler did not fire on the second run. The run output shows no RUNNING HANDLER section, and journalctl -u rsyslog records no restart at that timestamp.
  4. The check can fail. On a test host, delete the line and converge: the run must report changed=1, and the run after that must report changed=0. A check that reports success on a host you deliberately broke is not measuring anything.
  5. The service parses its configuration. rsyslogd -N1 returns success on a repaired host; a file that is correct and unparseable is a different incident starting.
  6. Forwarding is confirmed from the collector. Messages from a repaired host arrive once, not 214 times, measured at the destination rather than at the source.
  7. The CI gate rejects a regression. Reintroduce the anchored-pattern task on a branch and confirm the pipeline fails on the second converge.

Prevention

  • Run every role twice in CI and require changed=0 on the second pass. Idempotence is a property of the second run and there is no other way to observe it.
  • Alert on persistent changed in production, not only on failures. A host that never reaches changed=0 is either drifting or fighting itself, and both are worth a page eventually.
  • Use template for files you own. One description of the whole file, compared as a whole, cannot drift apart from its own matching rule.
  • Reserve lineinfile for a line inside a file another system owns, and when you use it, write the regexp against the exact string the task writes. If the line is later reformatted, the regexp is part of the same change.
  • Prefer search_string to regexp when you are matching a literal. It removes anchoring and escaping from the problem entirely.
  • Do not rely on --check to catch idempotence faults. Check mode validates prediction against action, and a task with wrong logic predicts its wrong action perfectly.
  • Look at old hosts, not new ones. Accumulation faults are invisible on a machine built yesterday, and the oldest host in the fleet is the best detector you have.