Pacemaker Log flooded with "Could not accept client connection: Too many open files in system"

It’s happened to multiple telecom giants, and in their PCRF implementation, pacemaker nodes failed with too many open files and
pacemaker logs get filled within a min and consume whole disk space, approx 90GB
The only error printed is “Could not accept client connection: Too many open files in the system.”

Note: It’s not an issue with the File limit, and the pacemaker spawns tons of processes and fills the logfile for less than a min.
Note: this issue is not with the pacemaker, but with Kernal Code (Please see the strace output)

core file size (blocks, -c) unlimited
data seg size (kbytes, -d) unlimited
scheduling priority (-e) 0
file size (blocks, -f) unlimited
pending signals (-i) 63192
max locked memory (kbytes, -l) 64
max memory size (kbytes, -m) unlimited
open files (-n) 65536
pipe size (512 bytes, -p) 8
POSIX message queues (bytes, -q) 819200
real-time priority (-r) 0
stack size (kbytes, -s) 8192
cpu time (seconds, -t) unlimited
max user processes (-u) 63192
virtual memory (kbytes, -v) unlimited
file locks (-x) unlimited

As the system was in bad shape, we could only extract the top and bottom of the file, and it’s all the same log lines.
We have log rotate, but even that won’t get triggered as the Log file gets filled in less than a min.

We are facing issues with multiple releases, and Focus is on CenOS 8.1

System 1 : CentOS Linux release 8.1.1911 (Core)
uname Output: Linux dc211-Installer 4.18.0-193.14.2.el8_2.x86_64 #1 SMP Sun Jul 26 03:54:29 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux
pacemaker-2.0.2-3.el8_1.2.rpm
pacemaker-libs-2.0.2-3.el8_1.2.rpm
pacemaker-cluster-libs-2.0.2-3.el8_1.2.rpm
pacemaker-schemas-2.0.2-3.el8_1.2.rpm
pacemaker-cli-2.0.2-3.el8_1.2.rpm

This is Just FYI; that same issue also happening with another Linux with pacemaker-2.1.0-8 as well.

System 2: AlmaLinux release 8.5 (Arctic Sphynx)
uname output: Linux dc222-Installer 4.18.0-372.9.1.el8.x86_64 #1 SMP Tue May 10 08:57:35 EDT 2022 x86_64 x86_64 x86_64 GNU/Linux

pacemaker-libs-2.1.0-8.el8.rpm
pacemaker-2.1.0-8.el8.rpm
pacemaker-schemas-2.1.0-8.el8.rpm
pacemaker-cli-2.1.0-8.el8.rpm
pacemaker-cluster-libs-2.1.0-8.el8.rpm

In one case, we could log in to the system and get the snippets to log snip from the top and bottom of the pacemaker.log file.

Please let me know if anything is needed from my side to resolve the issue.

Thanks
Iqbal Singh Aulakh

What is the business impact? Please also provide timeframe information.
System Crash, Business loss, Nationwide outage

Where are you experiencing the behavior? What environment?
Multiple Customers reported this issue

When does the behavior occur? Frequency? Repeatedly? At certain times?
Sep 15 04:16

Strace Output
----------------------

This is a txt file, please remove the pdf extension.

facter-trace.txt.pdf (927.1 KB)

Hi Experts.

Could you please help on this.

Thanks,
Kiran

Hello all,

I’m a colleague of Kiran and was involved in some cases during this. The issue arises when the puppet-related “facter” tool gathers assorted system information. During the “Filesystems” check, it accesses various /sys and /dev structures and finally hangs, as can be seen in the strace output, when it accesses the virtual cdrom:

openat(AT_FDCWD, “/dev/sr0”, O_RDONLY|O_CLOEXEC

Since several monitoring scripts run once per minute, and use this command, after a few hours, the CentOS max file descriptor limit (/proc/sys/fs/file-max, which is set to only 65536) is reached, and that causes Pacemaker’s log to grow uncontrollably). As it’s stuck in the kernel, the facter processes remain unkillable until the system is rebooted. Raising the max fd limit provided a temporary work-around but eventually system load becomes too great and necessitates a reboot.

This has been observed with both openstack and vmware hypervisors, so we’ve ruled out a hypervisor-related cause.

The particular kernel is:
Linux pcrfclient01 4.18.0-193.14.2.el8_2.x86_64 #1 SMP Sun Jul 26 03:54:29 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux

From the dmesg buffer at the time the following trace was observed:

[5722401.161440] INFO: task facter:1681874 blocked for more than 120 seconds.
[5722401.161744]       Not tainted 4.18.0-193.14.2.el8_2.x86_64 #1
[5722401.161997] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[5722401.162369] facter          D    0 1681874 1681870 0x00000080
[5722401.162629] Call Trace:
[5722401.162782]  ? __schedule+0x24f/0x650
[5722401.162953]  schedule+0x2f/0xa0
[5722401.163123]  schedule_preempt_disabled+0xa/0x10
[5722401.163329]  __mutex_lock.isra.5+0x2d0/0x4a0
[5722401.163525]  ? _cond_resched+0x15/0x30
[5722401.163699]  __blkdev_get+0x78/0x550
[5722401.163864]  ? bd_acquire+0xd0/0xd0
[5722401.164028]  do_dentry_open+0x132/0x330
[5722401.164235]  path_openat+0x573/0x14d0
[5722401.164409]  ? filename_lookup.part.63+0xe0/0x170
[5722401.164625]  ? audit_alloc_name+0x88/0xe0
[5722401.164810]  do_filp_open+0x93/0x100
[5722401.164980]  ? __check_object_size+0xa8/0x16b
[5722401.165210]  ? audit_alloc_name+0x88/0xe0
[5722401.165395]  do_sys_open+0x184/0x220
[5722401.165561]  do_syscall_64+0x5b/0x1a0
[5722401.165635]  entry_SYSCALL_64_after_hwframe+0x65/0xca

I was looking through kernel changelogs in recent years and saw this one in 4.9 from 2018. This should be present in the kernel (I admit I haven’t checked the source yet), but the desc sounds promising:

Author: Bart Van Assche <bart.vanassche@wdc.com>
Date:   Thu Aug 2 10:44:42 2018 -0700

    scsi: sr: Avoid that opening a CD-ROM hangs with runtime power management enabled
    
    commit 1214fd7b497400d200e3f4e64e2338b303a20949 upstream.
    
    Surround scsi_execute() calls with scsi_autopm_get_device() and
    scsi_autopm_put_device(). Note: removing sr_mutex protection from the
    scsi_cd_get() and scsi_cd_put() calls is safe because the purpose of
    sr_mutex is to serialize cdrom_*() calls.
    
    This patch avoids that complaints similar to the following appear in the
    kernel log if runtime power management is enabled:

The call trace doesn’t match up, though. I was hoping to find some clue that a future kernel might have the issue fixed, and was not able to discover any.

The issue is relatively rare and we’ve been unable to duplicate it ourselves.

Hi Alma Linux Experts,

Could you please share your thoughts on this, as we have been waiting for this information for a while.

Thanks,
Kiran