Inconsistent module behavior when using connection_local to write to same file in parallel

[karlism]

ISSUE TYPE

• Bug Report

COMPONENT NAME

lineinfile module

ANSIBLE VERSION

ansible 2.4.4.0
  config file = /home/username/.ansible.cfg
  configured module search path = [u'/home/username/.ansible/plugins/modules', u'/usr/share/ansible/plugins/modules']
  ansible python module location = /usr/local/lib/python2.7/site-packages/ansible
  executable location = /usr/local/bin/ansible
  python version = 2.7.14 (default, Mar 27 2018, 09:57:43) [GCC 4.2.1 Compatible OpenBSD Clang 5.0.1 (tags/RELEASE_501/final)]

CONFIGURATION

COLOR_VERBOSE(/home/username/.ansible.cfg) = cyan
DEFAULT_HASH_BEHAVIOUR(/home/username/.ansible.cfg) = merge
DEFAULT_HOST_LIST(/home/username/.ansible.cfg) = [u'/home/username/ansible/inventory']
DEFAULT_VAULT_PASSWORD_FILE(env: ANSIBLE_VAULT_PASSWORD_FILE) = /home/username/.ansible/vault_pass
DEPRECATION_WARNINGS(/home/username/.ansible.cfg) = False

OS / ENVIRONMENT

OpenBSD 6.3 amd64

SUMMARY

Files created or modified by lineinfile module are inconsistent when used as a local action, some new lines might be missing.

STEPS TO REPRODUCE

- hosts: "deploytest"
  gather_facts: False

  tasks:
    - lineinfile:
        path: "/tmp/bug_example.{{ number }}"
        line: "{{ inventory_hostname }}"
        create: yes
      connection: local

$ ansible --list-hosts deploytest
  hosts (6):
    deploytest1
    deploytest2
    deploytest3
    deploytest4
    deploytest5
    deploytest6

$ for i in 1 2 3 4 5; do ansible-playbook /tmp/lineinfile_bug.yml -e "number=$i" ; done

$ wc -l bug_example.*
       5 bug_example.1
       6 bug_example.2
       6 bug_example.3
       5 bug_example.4
       5 bug_example.5
      27 total

$ cat bug_example.1
deploytest2
deploytest3
deploytest5
deploytest1
deploytest6

$ cat bug_example.2
deploytest2
deploytest1
deploytest5
deploytest3
deploytest4
deploytest6

(as you can see deploytest4 is missing in the bug_example.1 file despite the fact that task run successfully for that host)

EXPECTED RESULTS

Generated results should be consistent on every run.

ACTUAL RESULTS

Some lines are missing from files.

[ansibot]

Files identified in the description:

• lib/ansible/modules/files/lineinfile.py

If these files are inaccurate, please update the component name section of the description or use the !component bot command.

click here for bot help

[ansibot]

cc @ahtik @dhozac
click here for bot help

[webknjaz]

-label needs_triage

[ansibot]

cc @samdoran
click here for bot help

[karlism]

I was able to reproduce this with Ansible 2.5.4 too:

ansible 2.5.4
  config file = /home/username/.ansible.cfg
  configured module search path = [u'/home/username/.ansible/plugins/modules', u'/usr/share/ansible/plugins/modules']
  ansible python module location = /usr/local/lib/python2.7/site-packages/ansible
  executable location = /usr/local/bin/ansible
  python version = 2.7.14 (default, Mar 27 2018, 09:57:43) [GCC 4.2.1 Compatible OpenBSD Clang 5.0.1 (tags/RELEASE_501/final)]

[db0]

I can confirm that this behaviour persists in ansible 2.7.7

ansible-playbook 2.7.7
  config file = /etc/ansible/ansible.cfg
  configured module search path = ['/home/db0/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /usr/lib/python3.7/site-packages/ansible
  executable location = /usr/bin/ansible-playbook
  python version = 3.7.1 (default, Nov  5 2018, 14:07:04) [GCC 8.2.1 20181011 (Red Hat 8.2.1-4)]

What I've noticed is that the lineinfile module sometimes seems to clobber the previous entries by somehow, and then you simply get only the latter entries in the final file. What's causing it is not obvious from verbose logs.

[db0]

I have traced this issue in the code of lineinfile.py and it seems to be caused by the way ansible modules are threaded and the timing of those threads.

Specifically, when the if in line 245 is called if not os.path.exists(b_dest): then at apparenty random times, it will return False, even if the file has already been created via the call to write_changes() in line 388 via a previous module call.

I have tested this extensively, and an ad-hoc check with os.path.isfile() at line 389 will always return true. And then a custom check just before line 245 with os.stat() from a following module execution, will inform that the file does not exist (in those instances where this bug appears), which naturally will trigger the wipe of the existing list via the statement in line 255.

I have tried various things to see why it's being caused and possible workarounds within lineinfile.py with no success. I think one would need to dig into the way modules are threaded in ansible, and I would be way out of my depth there.

I'll be glad to collaborate with anyone who wants to help resolve this.

[samdoran]

There is currently a lot of working going into adding file locking support in lineinfile. See #47322 and #52567.

This issue is most likely caused by multiple processes on the same host interacting with the same file. The lineinfile module reads the lines from the original, writes changes to a temporary file, then uses atomic_move() to overwrite the original file with the temporary copy. It is possible there is a race condition where one process is in the middle of this os.rename() operation while another process is trying to read and/or write the file.

You can try testing with #52567 to see if that fixes your issue.

[ansibot]

Files identified in the description:

• lib/ansible/modules/lineinfile.py

If these files are incorrect, please update the component name section of the description or use the !component bot command.

click here for bot help

[guybarzi]

I encountered this issue as well, my workaround was to perform the local_action lineinfile file writing in a different play, with serial set to 1. This way each line is written separately without interruptions.

[PricopeStefan]

Issue still present in Ansible version 2.10.5 and reproducible using the same steps as in the original post.

$ ansible --version
ansible 2.10.5
  config file = None
  configured module search path = ['/home/stefan/ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /home/stefan/.local/lib/python3.8/site-packages/ansible
  executable location = /home/stefan/.local/bin/ansible
  python version = 3.8.5 (default, Jul 28 2020, 12:59:40) [GCC 9.3.0]

Also I think it may affect the blockinfile module as well (the last host will overwrite the contents of the file no matter what). Only fix I found so far is to just use the shell module and echo the line into the file. It's not the prettiest solution but it gets the job somewhat done.

tasks:
  - name: "log using echo"
    connection: local
    shell: "/bin/echo {{ inventory_hostname }} >> /tmp/ansible_test/bug_example.{{ number }}"

[teknomar7]

I'm still able to produce this with the lineinfile module on Ansible Core 2.11.5. This seems to be a pretty significant issue that has been open for three years without being addressed. My use case is similar to what's described above. I have a task that looks for a file on a server, and if it exists writes the inventory hostname to a text file by delegating to localhost. The logs correctly show what should've been written to the file, but the count in the file is off significantly. This seems to work fine when setting serial to 1.

[samdoran]

It's a concurrency issue. Multiple processes writing to the same file at the same time, which is why serial: 1 makes it work as expected. The previous attempts to improve file locking were reverted for various reasons.

[s-hertel]

In addition to @samdoran's suggestion, you can also use throttle at the task level.

[bcoca]

quick explanation: you are writing to the same file in parallel, so you get a race condition with several forks writing their own version of the same file (last one wins). Both throttle: 1 and serial: 1 force the writes to happen one at a time

[s-hertel]

Closing per above