Salt: lsattr slowing down archive.extracted

Created on 13 Apr 2018  路  10Comments  路  Source: saltstack/salt

Description of Issue/Question

When using archive.extracted with user and group set, it loops through every file checking it's attributes, this is both ineffecient and slow. It makes my CPU usage peak and my states takes a solid 10 minutes to run.

What I'd like:

  • An option to turn the lsattr stuff off and just enforce the chown.
  • Rewrite the lsattr stuff to be more efficient (example: lsattr -R /var/folder)

Setup

(Please provide relevant configs and/or SLS files (Be sure to remove sensitive info).)

  archive.extracted:
    - name: /var/folder
    - source: s3://bucket/filename
    - skip_verify: True
    - user: user
    - group: user

Steps to Reproduce Issue

(Include debug logs if possible and relevant.)

2018-04-12 23:11:01,923 [salt.loaded.int.module.cmdmod:282 ][DEBUG   ][21519] output: --------------e---- /var/folder/node_modules/resolve-pkg/package.json
2018-04-12 23:11:02,108 [salt.loaded.int.module.cmdmod:385 ][INFO    ][21519] Executing command [u'lsattr', u'/var/folder/node_modules/resolve-pkg/index.js'] in directory '/root'
2018-04-12 23:11:02,517 [salt.loaded.int.module.cmdmod:282 ][DEBUG   ][21519] output: --------------e---- /var/folder/node_modules/resolve-pkg/index.js
2018-04-12 23:11:02,519 [salt.loaded.int.module.cmdmod:385 ][INFO    ][21519] Executing command [u'lsattr', u'/var/folder/node_modules/engine.io-client/History.md'] in directory '/root'
2018-04-12 23:11:03,133 [salt.loaded.int.module.cmdmod:282 ][DEBUG   ][21519] output: --------------e---- /var/folder/node_modules/engine.io-client/History.md
2018-04-12 23:11:03,135 [salt.loaded.int.module.cmdmod:385 ][INFO    ][21519] Executing command [u'lsattr', u'/var/folder/node_modules/engine.io-client/engine.io.js'] in directory '/root'
2018-04-12 23:11:03,704 [salt.loaded.int.module.cmdmod:282 ][DEBUG   ][21519] output: --------------e---- /var/folder/node_modules/engine.io-client/engine.io.js
2018-04-12 23:11:03,707 [salt.loaded.int.module.cmdmod:385 ][INFO    ][21519] Executing command [u'lsattr', u'/var/folder/node_modules/engine.io-client/README.md'] in directory '/root'
2018-04-12 23:11:04,280 [salt.loaded.int.module.cmdmod:282 ][DEBUG   ][21519] output: --------------e---- /var/folder/node_modules/engine.io-client/README.md
2018-04-12 23:11:04,282 [salt.loaded.int.module.cmdmod:385 ][INFO    ][21519] Executing command [u'lsattr', u'/var/folder/node_modules/engine.io-client/package.json'] in directory '/root'
2018-04-12 23:11:04,750 [salt.loaded.int.module.cmdmod:282 ][DEBUG   ][21519] output: --------------e---- /var/folder/node_modules/engine.io-client/package.json
2018-04-12 23:11:04,832 [salt.loaded.int.module.cmdmod:385 ][INFO    ][21519] Executing command [u'lsattr', u'/var/folder/node_modules/engine.io-client/LICENSE'] in directory '/root'
2018-04-12 23:11:05,509 [salt.loaded.int.module.cmdmod:282 ][DEBUG   ][21519] output: --------------e---- /var/folder/node_modules/engine.io-client/LICENSE
2018-04-12 23:11:05,611 [salt.loaded.int.module.cmdmod:385 ][INFO    ][21519] Executing command [u'lsattr', u'/var/folder/node_modules/engine.io-client/index.js'] in directory '/root'
2018-04-12 23:11:06,207 [salt.loaded.int.module.cmdmod:282 ][DEBUG   ][21519] output: --------------e---- /var/folder/node_modules/engine.io-client/index.js
2018-04-12 23:11:06,308 [salt.loaded.int.module.cmdmod:385 ][INFO    ][21519] Executing command [u'lsattr', u'/var/folder/node_modules/engine.io-client/lib/xmlhttprequest.js'] in directory '/root'
2018-04-12 23:11:06,639 [salt.loaded.int.module.cmdmod:282 ][DEBUG   ][21519] output: --------------e---- /var/folder/node_modules/engine.io-client/lib/xmlhttprequest.js
2018-04-12 23:11:06,718 [salt.loaded.int.module.cmdmod:385 ][INFO    ][21519] Executing command [u'lsattr', u'/var/folder/node_modules/engine.io-client/lib/transport.js'] in directory '/root'
2018-04-12 23:11:07,315 [salt.loaded.int.module.cmdmod:282 ][DEBUG   ][21519] output: --------------e---- /var/folder/node_modules/engine.io-client/lib/transport.js
2018-04-12 23:11:07,395 [salt.loaded.int.module.cmdmod:385 ][INFO    ][21519] Executing command [u'lsattr', u'/var/folder/node_modules/engine.io-client/lib/socket.js'] in directory '/root'
2018-04-12 23:11:07,865 [salt.loaded.int.module.cmdmod:282 ][DEBUG   ][21519] output: --------------e---- /var/folder/node_modules/engine.io-client/lib/socket.js
2018-04-12 23:11:07,867 [salt.loaded.int.module.cmdmod:385 ][INFO    ][21519] Executing command [u'lsattr', u'/var/folder/node_modules/engine.io-client/lib/index.js'] in directory '/root'
2018-04-12 23:11:08,459 [salt.loaded.int.module.cmdmod:282 ][DEBUG   ][21519] output: --------------e---- /var/folder/node_modules/engine.io-client/lib/index.js
2018-04-12 23:11:08,482 [salt.loaded.int.module.cmdmod:385 ][INFO    ][21519] Executing command [u'lsattr', u'/var/folder/node_modules/engine.io-client/lib/transports/polling-xhr.js'] in directory '/root'
2018-04-12 23:11:09,238 [salt.loaded.int.module.cmdmod:282 ][DEBUG   ][21519] output: --------------e---- /var/folder/node_modules/engine.io-client/lib/transports/polling-xhr.js
2018-04-12 23:11:09,240 [salt.loaded.int.module.cmdmod:385 ][INFO    ][21519] Executing command [u'lsattr', u'/var/folder/node_modules/engine.io-client/lib/transports/websocket.js'] in directory '/root'
2018-04-12 23:11:09,650 [salt.loaded.int.module.cmdmod:282 ][DEBUG   ][21519] output: --------------e---- /var/folder/node_modules/engine.io-client/lib/transports/websocket.js
2018-04-12 23:11:09,668 [salt.loaded.int.module.cmdmod:385 ][INFO    ][21519] Executing command [u'lsattr', u'/var/folder/node_modules/engine.io-client/lib/transports/polling-jsonp.js'] in directory '/root'
2018-04-12 23:11:10,179 [salt.loaded.int.module.cmdmod:282 ][DEBUG   ][21519] output: --------------e---- /var/folder/node_modules/engine.io-client/lib/transports/polling-jsonp.js
2018-04-12 23:11:10,181 [salt.loaded.int.module.cmdmod:385 ][INFO    ][21519] Executing command [u'lsattr', u'/var/folder/node_modules/engine.io-client/lib/transports/polling.js'] in directory '/root'

Versions Report

(Provided by running salt --versions-report. Please also mention any differences in master/minion versions.)

Master:

Salt Version:
           Salt: 2018.3.0

Dependency Versions:
           cffi: 1.11.4
       cherrypy: unknown
       dateutil: 2.6.1
      docker-py: Not Installed
          gitdb: 2.0.0
      gitpython: 2.1.1
          ioflo: Not Installed
         Jinja2: 2.7.2
        libgit2: 0.24.5
        libnacl: Not Installed
       M2Crypto: Not Installed
           Mako: 0.9.1
   msgpack-pure: Not Installed
 msgpack-python: 0.4.8
   mysql-python: Not Installed
      pycparser: 2.18
       pycrypto: 2.6.1
   pycryptodome: Not Installed
         pygit2: 0.24.2
         Python: 2.7.13 (default, Nov 24 2017, 17:33:09)
   python-gnupg: Not Installed
         PyYAML: 3.11
          PyZMQ: 16.0.2
           RAET: Not Installed
          smmap: 2.0.1
        timelib: Not Installed
        Tornado: 4.5.3
            ZMQ: 4.1.6

System Versions:
           dist: debian 9.4
         locale: UTF-8
        machine: x86_64
        release: 4.9.0-6-amd64
         system: Linux
        version: debian 9.4

Minion:

Salt Version:
           Salt: 2018.3.0

Dependency Versions:
           cffi: 1.11.4
       cherrypy: Not Installed
       dateutil: 2.2
      docker-py: Not Installed
          gitdb: Not Installed
      gitpython: Not Installed
          ioflo: Not Installed
         Jinja2: 2.7.2
        libgit2: Not Installed
        libnacl: Not Installed
       M2Crypto: Not Installed
           Mako: 0.9.1
   msgpack-pure: Not Installed
 msgpack-python: 0.4.8
   mysql-python: Not Installed
      pycparser: 2.18
       pycrypto: 2.6.1
   pycryptodome: Not Installed
         pygit2: Not Installed
         Python: 2.7.13 (default, Nov 24 2017, 17:33:09)
   python-gnupg: Not Installed
         PyYAML: 3.11
          PyZMQ: 16.0.2
           RAET: Not Installed
          smmap: Not Installed
        timelib: Not Installed
        Tornado: 4.5.3
            ZMQ: 4.1.6

System Versions:
           dist: debian 9.4
         locale: UTF-8
        machine: x86_64
        release: 4.9.0-6-amd64
         system: Linux
        version: debian 9.4

Please feel free to ask for any more info if this isn't sufficient.

Bug P2 fixed-pending-your-verification severity-medium
Source
picture xBytez
👍7

Most helpful comment

There's a similar issue with other states as well (i.e: with file.directory and recursive permissions).
States that used to take seconds can now take 10 mins to complete.

picture rmarchei on 14 Jun 2018
👍4

All 10 comments

@xBytez Thanks for the report. Ideally we would want to ensure the lsattr portion is being as efficient as possible.

garethgreenaway picture garethgreenaway on 13 Apr 2018

There's a similar issue with other states as well (i.e: with file.directory and recursive permissions).
States that used to take seconds can now take 10 mins to complete.

rmarchei picture rmarchei on 14 Jun 2018
👍4

I have this issue as well. If I run file.directory or anything specifying user + group, lsattr runs forever.
35 min if I have several file.directory calls.
COuld we get an update on this please?

Gabri-connect picture Gabri-connect on 3 Jul 2018

Can confirm. With debug on you get 38865 log lines for 13254 files and spent close to two minutes.
Example:

# setup
rm -rf /tmp/foo && mkdir -p /tmp/foo/bar/bat && find /tmp/foo -type d -exec cp /dev/null {}/file.txt \;

# run
salt-call -l debug state.single file.directory /tmp/foo user=root group=root dir_mode=750 makedirs=True file_mode=644 recurse="['user', 'group', 'mode']"

# output
...
[INFO    ] Executing command [u'lsattr', u'/tmp/foo/file.txt'] in directory '/root'
[DEBUG   ] stdout: ---------------- /tmp/foo/file.txt
[DEBUG   ] output: ---------------- /tmp/foo/file.txt
[INFO    ] Executing command [u'lsattr', u'/tmp/foo/bar/file.txt'] in directory '/root'
[DEBUG   ] stdout: ---------------- /tmp/foo/bar/file.txt
[DEBUG   ] output: ---------------- /tmp/foo/bar/file.txt
...

Can this be fixed by adding output_loglevel=warn (or similar) in "file.lsattr"s call to cmd.run. This or a loglevel parameter for file.lsattr - which toggles cmd.run debug level?

Not sure of what the author of file.lsattr had in mind, but maybe @terminalmage can have a look?

sastorsl picture sastorsl on 21 Sep 2018
👍3

This is really bad. Are there any plans to have it fixed?

sergeyfd picture sergeyfd on 3 Jan 2019

The problem is in this block in file.py. This enforcement is extremely expensive for directories with many files. It should be optional, I think.

 `if not salt.utils.platform.is_windows() and not is_dir and not is_link:
    try:
        lattrs = lsattr(name)
    except SaltInvocationError:
        lattrs = None
    if lattrs is not None:
        # List attributes on file
        perms['lattrs'] = ''.join(lattrs.get(name, ''))
        # Remove attributes on file so changes can be enforced.
        if perms['lattrs']:
            chattr(name, operator='remove', attributes=perms['lattrs'])`
sergeyfd picture sergeyfd on 3 Jan 2019

Fixed in https://github.com/saltstack/salt/pull/51044.

terminalmage picture terminalmage on 3 Jan 2019

Thanks, that makes total sense.

sergeyfd picture sergeyfd on 3 Jan 2019

Is this still an open issue?

mchugh19 picture mchugh19 on 3 Mar 2019

No, it can be closed.

sergeyfd picture sergeyfd on 9 Mar 2019
Was this page helpful?
0 / 5 - 0 ratings

Related issues

lhost picture lhost  路  3Comments
qiushics picture qiushics  路  3Comments
mooperd picture mooperd  路  3Comments
seanacais picture seanacais  路  3Comments
sfozz picture sfozz  路  3Comments