Author Topic: High CPU on large directory listings  (Read 156 times)

Offline xelneon

  • New user
  • *
  • Posts: 12
    • View Profile
High CPU on large directory listings
« on: July 13, 2017, 04:33:35 pm »
Hello,

I'm noticing very high CPU usage (40% on a single core) when getting larger directory listings (2000+ directories). This is running Proftpd 1.3.6.

Any ideas as to what might cause this? The configuration is very close to the default, with only a few minor changes.

Thanks

Offline castaglia

  • Administrator
  • Support Hero
  • *****
  • Posts: 5359
    • View Profile
    • http://www.castaglia.org/
Re: High CPU on large directory listings
« Reply #1 on: July 13, 2017, 05:58:34 pm »
How is the directory listing being done?  Using FTP, or FTPS, or SFTP?  What is the command being used by the client?

Offline xelneon

  • New user
  • *
  • Posts: 12
    • View Profile
Re: High CPU on large directory listings
« Reply #2 on: July 13, 2017, 06:47:29 pm »
I've tested with FTP and FTPS, both have the same CPU usage problem. The client is FileZilla and it's issuing the MLSD command. I've also tested forcing it to use LIST instead and the high CPU usage is still there.

Offline castaglia

  • Administrator
  • Support Hero
  • *****
  • Posts: 5359
    • View Profile
    • http://www.castaglia.org/
Re: High CPU on large directory listings
« Reply #3 on: July 14, 2017, 02:09:18 am »
Interesting.  I'm not able to reproduce this behavior locally.  Could you provide the following, please?
 * proftpd.conf
 * output of `proftpd -V`

Also, for the directories being listed -- are they on a network-mounted filesystem, perhaps?  If not, what filesystem type are you using?
« Last Edit: July 14, 2017, 02:29:41 am by castaglia »

Offline xelneon

  • New user
  • *
  • Posts: 12
    • View Profile
Re: High CPU on large directory listings
« Reply #4 on: July 14, 2017, 02:48:06 am »
The filesystem is XFS and it's local.

ServerIdent                     "ProFTPD Default Installation"
ServerType                      standalone
DefaultServer                   on
UseReverseDNS                   off
UseEncoding                     on
MaxClientsPerHost               30
MaxClientsPerUser               10

ExtendedLog /var/log/proftpd.log ALL default

Port                            21

Umask                           022

User                            proftpd
Group                           proftpd

DefaultRoot ~

AllowOverwrite          off

    TLSEngine on

    TLSProtocol TLSv1 TLSv1.1 TLSv1.2

    TLSServerCipherPreference on

    TLSCipherSuite ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES128-SHA:AES128-GCM-SHA256:AES128-SHA

    TLSRequired off

    TLSRSACertificateFile /etc/ssl/private/rsa.pem
    TLSRSACertificateKeyFile /etc/ssl/private/rsa.pem

    TLSECCertificateFile /etc/ssl/private/ecc.pem
    TLSECCertificateKeyFile /etc/ssl/private/ecc.pem

Compile-time Settings:
  Version: 1.3.6 (stable)
  Platform: LINUX [Linux 3.2.90 x86_64]
  Built: Wed Jul 12 2017 21:28:27 UTC
  Built With:
    configure  '--prefix=/opt/proftpd' '--with-openssl-cmdline=/opt/openssl/bin/openssl' '--disable-ipv6' '--disable-ident' '--disable-auth-file' '--disable-auth-pam' '--enable-nls' '--enable-openssl' '--with-modules=mod_tls:mod_sql:mod_sql_mysql' '--with-includes=/opt/openssl/include' '--with-libraries=/opt/openssl/lib'

  CFLAGS: -g2 -O2 -Wall -fno-omit-frame-pointer
  LDFLAGS: -L$(top_srcdir)/lib  -rdynamic -L/opt/openssl/lib -L/usr/lib64/mysql
  LIBS:  -lssl -lcrypto -L$(top_srcdir)/lib/libcap -lcap  -lm -lmysqlclient -lz  -lssl -lcrypto -lsupp -lcrypt -ldl

  Files:
    Configuration File:
      /opt/proftpd/etc/proftpd.conf
    Pid File:
      /opt/proftpd/var/proftpd.pid
    Scoreboard File:
      /opt/proftpd/var/proftpd.scoreboard

  Info:
    + Max supported UID: 4294967295
    + Max supported GID: 4294967295

  Features:
    - Autoshadow support
    - Controls support
    + curses support
    - Developer support
    - DSO support
    - IPv6 support
    + Largefile support
    - Lastlog support
    - Memcache support
    + ncursesw support
    + NLS support
    - Redis support
    - Sodium support
    + OpenSSL support
    - PCRE support
    - POSIX ACL support
    + Shadow file support
    + Sendfile support
    + Trace support
    + xattr support

  Tunable Options:
    PR_TUNABLE_BUFFER_SIZE = 1024
    PR_TUNABLE_DEFAULT_RCVBUFSZ = 8192
    PR_TUNABLE_DEFAULT_SNDBUFSZ = 8192
    PR_TUNABLE_ENV_MAX = 2048
    PR_TUNABLE_GLOBBING_MAX_MATCHES = 100000
    PR_TUNABLE_GLOBBING_MAX_RECURSION = 8
    PR_TUNABLE_HASH_TABLE_SIZE = 40
    PR_TUNABLE_LOGIN_MAX = 256
    PR_TUNABLE_NEW_POOL_SIZE = 512
    PR_TUNABLE_PATH_MAX = 4096
    PR_TUNABLE_SCOREBOARD_BUFFER_SIZE = 80
    PR_TUNABLE_SCOREBOARD_SCRUB_TIMER = 30
    PR_TUNABLE_SELECT_TIMEOUT = 30
    PR_TUNABLE_TIMEOUTIDENT = 10
    PR_TUNABLE_TIMEOUTIDLE = 600
    PR_TUNABLE_TIMEOUTLINGER = 10
    PR_TUNABLE_TIMEOUTLOGIN = 300
    PR_TUNABLE_TIMEOUTNOXFER = 300
    PR_TUNABLE_TIMEOUTSTALLED = 3600
    PR_TUNABLE_XFER_SCOREBOARD_UPDATES = 10

Offline castaglia

  • Administrator
  • Support Hero
  • *****
  • Posts: 5359
    • View Profile
    • http://www.castaglia.org/
Re: High CPU on large directory listings
« Reply #5 on: July 14, 2017, 05:11:55 am »
You might try seeing if the CPU usage is caused by encoding; you can test this by turning encoding off:

  UseEncoding off

Next, you might see if the checking for extended attributes uses the CPU more than expected; you can disable xattr support in the config file by using:

  FSOptions IgnoreExtendedAttributes

See:
  http://www.proftpd.org/docs/modules/mod_core.html#FSOptions

Offline xelneon

  • New user
  • *
  • Posts: 12
    • View Profile
Re: High CPU on large directory listings
« Reply #6 on: July 14, 2017, 06:50:42 am »
Just tried all of those, no change.

Edit: I compiled version 1.3.5e and used the exact same configure line and proftpd.conf, the CPU usage is much lower, 3% compared to 40%. I'm also using strace on the proftpd process and I'm seeing a lot of unnecessary stat and lstat calls on both versions.

Version 1.3.5e:

lstat("/", {st_mode=S_IFDIR|0755, st_size=88, ...}) = 0
lstat("/Example", {st_mode=S_IFDIR|0755, st_size=92, ...}) = 0
lstat("/Example/Example", {st_mode=S_IFDIR|0755, st_size=65, ...}) = 0
lstat("/Example/Example/Example", {st_mode=S_IFDIR|0755, st_size=81920, ...}) = 0
lstat("/Example/Example/Example/Example", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
stat("/Example/Example/Example/Example", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
stat("/Example/Example/Example/Example", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
stat("/Example/Example/Example/Example", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
stat("/Example/Example/Example/Example", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0

Version 1.3.6:

time(NULL)                              = 1500024332
time(NULL)                              = 1500024332
time(NULL)                              = 1500024332
stat("/Example/Example/Example/Example", {st_mode=S_IFDIR|0755, st_size=41, ...}) = 0
time(NULL)                              = 1500024332
time(NULL)                              = 1500024332
time(NULL)                              = 1500024332
time(NULL)                              = 1500024332
time(NULL)                              = 1500024332
lstat("/Example/Example/Example/Example", {st_mode=S_IFDIR|0755, st_size=41, ...}) = 0
time(NULL)                              = 1500024332
time(NULL)                              = 1500024332
lstat("/Example/Example/Example/Example", {st_mode=S_IFDIR|0755, st_size=41, ...}) = 0
time(NULL)                              = 1500024332
stat("/Example/Example/Example/Example", {st_mode=S_IFDIR|0755, st_size=41, ...}) = 0
time(NULL)                              = 1500024332
time(NULL)                              = 1500024332
time(NULL)                              = 1500024332
« Last Edit: July 14, 2017, 09:29:53 am by xelneon »

Offline castaglia

  • Administrator
  • Support Hero
  • *****
  • Posts: 5359
    • View Profile
    • http://www.castaglia.org/
Re: High CPU on large directory listings
« Reply #7 on: July 14, 2017, 03:46:28 pm »
If you are not using .ftpaccess files, you might also add:

  AllowOverride off

to your proftpd.conf; many of those lstat(2) checks are for .ftpaccess files in the parent directories of files.

Offline xelneon

  • New user
  • *
  • Posts: 12
    • View Profile
Re: High CPU on large directory listings
« Reply #8 on: July 14, 2017, 04:23:56 pm »
None of those are from .ftpaccess, I had it disabled before testing.

Offline castaglia

  • Administrator
  • Support Hero
  • *****
  • Posts: 5359
    • View Profile
    • http://www.castaglia.org/
Re: High CPU on large directory listings
« Reply #9 on: July 14, 2017, 09:16:03 pm »
Hrm.  Would've expected to see "AllowOverride off" in the provided config, then.  Oh well.

As a mitigating measure, while we track down the cause, you might look into using:

  http://www.proftpd.org/docs/contrib/mod_statcache.html

Offline xelneon

  • New user
  • *
  • Posts: 12
    • View Profile
Re: High CPU on large directory listings
« Reply #10 on: July 15, 2017, 03:42:29 am »
It wasn't in the config originally, but when I started testing with strace it was. I also enabled mod_statcache and it seems to segfault when enabled while getting a directory listing that has more than a few directories in it.

At first the stack trace wasn't showing any details in the log, even with --enable-devel=stacktrace. I was able to get it to show details once I disabled DefaultRoot ~.

Code: [Select]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): -----BEGIN STACK TRACE-----
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): [0] proftpd: testing - 1.2.3.4: MLSD() [0x506e81]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): [1] proftpd: testing - 1.2.3.4: MLSD() [0x506e81]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): [2] proftpd: testing - 1.2.3.4: MLSD() [0x507a1e]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): [3] proftpd: testing - 1.2.3.4: MLSD() [0x45cd6f]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): [4] proftpd: testing - 1.2.3.4: MLSD(pr_fsio_stat+0xfd) [0x463a56]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): [5] proftpd: testing - 1.2.3.4: MLSD(dir_check_full+0x149) [0x42b39b]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): [6] proftpd: testing - 1.2.3.4: MLSD(dir_check+0x19e) [0x42bd54]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): [7] proftpd: testing - 1.2.3.4: MLSD() [0x4c95d4]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): [8] proftpd: testing - 1.2.3.4: MLSD(pr_module_call+0xa6) [0x451a56]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): [9] proftpd: testing - 1.2.3.4: MLSD() [0x417967]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): [10] proftpd: testing - 1.2.3.4: MLSD(pr_cmd_dispatch_phase+0x2b2) [0x4183e2]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): [11] proftpd: testing - 1.2.3.4: MLSD(pr_cmd_dispatch+0x31) [0x4187b0]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): [12] proftpd: testing - 1.2.3.4: MLSD() [0x418c28]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): [13] proftpd: testing - 1.2.3.4: MLSD() [0x419f41]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): [14] proftpd: testing - 1.2.3.4: MLSD() [0x41a750]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): [15] proftpd: testing - 1.2.3.4: MLSD() [0x41abba]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): [16] proftpd: testing - 1.2.3.4: MLSD(main+0x970) [0x41b9d8]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): [17] /lib64/libc.so.6(__libc_start_main+0xfd) [0x7fabaf4f3d1d]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): [18] proftpd: testing - 1.2.3.4: MLSD() [0x416cc9]
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): -----END STACK TRACE-----
2017-07-15 03:36:26,068 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): ProFTPD terminating (signal 11)
2017-07-15 03:36:26,069 localhost.localdomain proftpd[27333] 127.0.0.1 (1.2.3.4[1.2.3.4]): notice: user testing: aborting transfer: Data connection closed

Offline castaglia

  • Administrator
  • Support Hero
  • *****
  • Posts: 5359
    • View Profile
    • http://www.castaglia.org/
Re: High CPU on large directory listings
« Reply #11 on: July 15, 2017, 07:15:52 am »
What's the mod_statcache config you're using?  E.g. how much memory did you allocate for it?

Offline xelneon

  • New user
  • *
  • Posts: 12
    • View Profile
Re: High CPU on large directory listings
« Reply #12 on: July 15, 2017, 09:12:05 am »
After increasing the memory for it the segfaults stopped. The CPU usage is still the same when loading large directories, however. I'm seeing spikes of 40% on a single core, even smaller directories are showing 3-9%.

Offline castaglia

  • Administrator
  • Support Hero
  • *****
  • Posts: 5359
    • View Profile
    • http://www.castaglia.org/
Re: High CPU on large directory listings
« Reply #13 on: July 15, 2017, 04:08:47 pm »
What kind of environment/machine are you running ProFTPD on?  The comment about increasing memory makes me wonder whether ProFTPD is running in a very constrained environment (hardware, or container, or cgroups limits, or somesuch)...

Offline xelneon

  • New user
  • *
  • Posts: 12
    • View Profile
Re: High CPU on large directory listings
« Reply #14 on: July 16, 2017, 04:00:12 am »
By memory, I meant increasing the StatCacheCapacity count. The server it's running on is an E3-1270v3, 32GB Ram, Intel 730 SSD. It's a development server, so there's no one on it but me.

The distro is CentOS 6.9 with a custom compiled kernel 3.2.90 from kernel.org.