php-fpm: pool nginx (php-fpm) eats all CPU

Topogigio · Nov 6, 2020, 11:45 AM

Hi,
I have a pfSense with performance problems (packets lost and so on). I noticed that suddenly "php-fpm: pool nginx (php-fpm) starts" eating CPU. After a while, in Status / Monitoring I find that "processes" go to zero, then back to about 340.

I have this problem also if nobody is connected to pfSense GUI, so I cannot explain what php is doing. I also monitor this pfSense using Zabbix, and my historic data reports many times "zero idle cpu available".

the pfSense is over VMWare, managing some static NAT and about 25 ipsec VTI, that are performing a really small traffic (and it seems there isn't any time correlation between traffic over VPNs as CPU exaustion)
It's
2.4.5-RELEASE-p1
CPU Type Intel(R) Xeon(R) Gold 6240 CPU @ 2.60GHz
AES-NI CPU Crypto: Yes (active)
Hardware crypto AES-CBC,AES-XTS,AES-GCM,AES-ICM

any idea?
thanks

kiokoman · Nov 6, 2020, 2:01 PM

packages installed ?
screenshot of diagnostic / system activity
you can check what's going on with
truss -p PID-of-php-fpm
and
lsof -p PID-of-php-fpm

example

[2.5.0-DEVELOPMENT][root@pfSense.kiokoman.home]/root: ps aux | grep php-fpm
root     340   0.0  0.3 103964 25728  -  Ss   02:14      0:01.56 php-fpm: master process (/usr/local/lib/php-fpm.conf) (php-fpm)
root   11873   0.0  0.5 108896 40584  -  I    02:14      0:04.72 php-fpm: pool nginx (php-fpm)
root   92839   0.0  0.5 106124 39228  -  I    02:14      0:08.22 php-fpm: pool nginx (php-fpm)
root   96219   0.0  0.0  11192  2496  1  S+   13:05      0:00.00 grep php-fpm
[2.5.0-DEVELOPMENT][root@pfSense.kiokoman.home]/root: lsof -p 11873
COMMAND   PID USER   FD   TYPE             DEVICE SIZE/OFF    NODE NAME
php-fpm 11873 root  cwd   VDIR              0,114     1536       2 /var/run
php-fpm 11873 root  rtd   VDIR              0,109     1024       2 /
php-fpm 11873 root    0u  VCHR               0,44      0t0      44 /dev/null
php-fpm 11873 root    1u  VCHR               0,44      0t0      44 /dev/null
php-fpm 11873 root    2u  VCHR               0,44      0t0      44 /dev/null
php-fpm 11873 root    3u  unix 0xfffff8003207aa38      0t0         ->(none)
php-fpm 11873 root    4u  IPv4 0xfffff800320380a0      0t0     UDP *:*
php-fpm 11873 root    5u  IPv6 0xfffff80032038080      0t0     UDP *:*
php-fpm 11873 root    6u  IPv4 0xfffff8003200c1e8      0t0     RAW *:*
php-fpm 11873 root    7u  sock                         0t0         no further information on family 0x20
php-fpm 11873 root    8u  unix 0xfffff80007f7f6d0      0t0         ->0xfffff80007f7f368
php-fpm 11873 root    9u  unix 0xfffff80007f7f368      0t0         ->0xfffff80007f7f6d0
php-fpm 11873 root   10u  VREG              0,109        0 3049730 / (/dev/ufsid/5e7f4db1653191cd)
php-fpm 11873 root   11                                            no more information; ty=0 file may be closing
php-fpm 11873 root   12u  unix 0xfffff80007ff26d0      0t0         /var/run/php-fpm.socket
php-fpm 11873 root   13u  unix 0xfffff8003207e368      0t0         ->0xfffff80064c48a38

Topogigio · Nov 6, 2020, 12:17 PM

@kiokoman said in php-fpm: pool nginx (php-fpm) eats all CPU:

truss -p PID-of-php-fpm

packages

frr (used for OSPF on VPNs)
haproxy (not used, it's not enabled currently, it was uses in the past)
openVM tools
openvpn-client-export
zabbix-agent5

I will take other data ASAP when I will get php high CPU load.

Meantime, thanks

kiokoman · Nov 6, 2020, 1:27 PM

also, check if there is something useful under
Status / System Logs /System / General
and IPsec logs if you have trouble with that section

Topogigio · Nov 6, 2020, 1:27 PM

@kiokoman in logs I found a lot of this related to php-fpm:

Nov 6 13:51:06 	php-fpm 	32031 	/rc.newipsecdns: Gateway, none 'available' for inet6, use the first one configured. ''

some of

php-fpm 	32031 	/rc.newipsecdns: IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.

that I cannot explain, nothing has changed IP

and sometimes it restarts tunnels (not all at same moment), eg:

Nov 6 13:06:15 	rc.gateway_alarm 	84397 	>>> Gateway alarm: F011XXX11_VTIV4 (Addr:10.77.36.86 Alarm:0 RTT:19.540ms RTTsd:14.562ms Loss:20%)
Nov 6 13:06:15 	check_reload_status 		updating dyndns F011XXXX11_VTIV4
Nov 6 13:06:15 	check_reload_status 		Restarting ipsec tunnels
Nov 6 13:06:15 	check_reload_status 		Restarting OpenVPN tunnels/interfaces
Nov 6 13:06:15 	check_reload_status 		Reloading filter

diags:

ps aux | grep php-fpm
root    56408 27.0  4.3 97048 42796  -  R    20:21       8:55.57 php-fpm: pool nginx (php-fpm)
root    32031 25.0  4.5 99292 44356  -  S    11:38       7:51.54 php-fpm: pool nginx (php-fpm)
root    76285  2.0  4.3 97048 42552  -  S    12:27       5:28.28 php-fpm: pool nginx (php-fpm)
root    42487  1.0  4.5 99292 44864  -  S    12:51       4:57.44 php-fpm: pool nginx (php-fpm)
root      340  0.0  2.6 94868 25468  -  Ss    2Sep20     2:28.70 php-fpm: master process (/usr/local/lib/php-f
root    22932  0.0  4.2 97048 41500  -  S    13:21       4:47.64 php-fpm: pool nginx (php-fpm)
root    40549  0.0  4.3 97048 42768  -  S    14:09       0:09.41 php-fpm: pool nginx (php-fpm)
root    64085  0.0  4.3 97048 42632  -  S    02:01       9:06.35 php-fpm: pool nginx (php-fpm)
root    64301  0.0  4.5 99228 44776  -  S    10:50       9:04.06 php-fpm: pool nginx (php-fpm)
myuser      7648  0.0  0.0   416   324  0  R+   14:18       0:00.00 grep php-fpm

but then:

truss -p 56408
truss: can not attach to target process: Operation not permitted

and

[2.4.5-RELEASE][]/home/myuser: lsof -p 56408
lsof: Command not found.

Topogigio · Nov 6, 2020, 2:01 PM

@kiokoman said in php-fpm: pool nginx (php-fpm) eats all CPU:

screenshot of diagnostic / system activity

kiokoman · Nov 6, 2020, 3:10 PM

you can install lsof with

pkg install lsof

the process consuming wcpu is PID 64085 and 64301
check that

are you using ipv6 with ipsec ? dual stack? ikev2 ?

Topogigio · Nov 6, 2020, 3:18 PM

@kiokoman I'm not using IPv6 (but not explicitly disabled nothing about it, if there are defaults).
All 25 IPSEC VTI site-to-site are IKEV2.

lsof installed thanks. ASAP I will find php with high CPU I'll debug

kiokoman · Nov 6, 2020, 3:45 PM

@Topogigio said in php-fpm: pool nginx (php-fpm) eats all CPU:

Gateway, none 'available' for inet6, use the first one configured. ''

this string come from /etc/inc/gwlb.inc

if (isset($gateways_arr[$gwdefault])) {
                // the configured gateway is a regular one. (not a gwgroup) use it as is..
                $set_dfltgwname = $gwdefault;
        } elseif (empty($gwdefault)) {
                // 'automatic' mode, pick the first one thats 'up' or 'unmonitored' which is always considered up
                $gateways_arr = order_gateways_as_configured($gateways_arr);

you can try to set System / Routing / Gateways
set it statically instead of automatic

Topogigio · Nov 6, 2020, 3:52 PM

@kiokoman assigned to "none", thanks

kiokoman · Nov 7, 2020, 4:52 PM

risolto? or do you still have high CPU usage?

Topogigio · Nov 7, 2020, 4:52 PM

@kiokoman currenlty is ok, and during last 24 hours status/monitoring does not report any down, nor my Zabbix high CPU usage.

But is't Saturday, so not a "normal" day, I need to check this next week.

No more logs related to IPv6 gateway anyway.

Meantime thanks

Topogigio · Nov 9, 2020, 8:36 AM

@kiokoman Today it started again.

[2.4.5-RELEASE][admin@gw01]/root: lsof -p 52202
lsof: WARNING: access /root/.lsof_gw01: No such file or directory
lsof: WARNING: created device cache file: /root/.lsof_gw01
COMMAND   PID USER   FD   TYPE             DEVICE SIZE/OFF   NODE NAME
php-fpm 52202 root  cwd   VDIR               0,82     4608 481536 /etc
php-fpm 52202 root  rtd   VDIR               0,82     1024      2 /
php-fpm 52202 root    0u  VCHR               0,17      0t0     17 /dev/null
php-fpm 52202 root    1u  VCHR               0,17      0t0     17 /dev/null
php-fpm 52202 root    2u  VCHR               0,17      0t0     17 /dev/null
php-fpm 52202 root    3u  unix 0xfffff80004d6ea38      0t0        ->(none)
php-fpm 52202 root    4u  IPv4 0xfffff80004eb4040      0t0    UDP *:*
php-fpm 52202 root    5u  IPv6 0xfffff80004eb4020      0t0    UDP *:*
php-fpm 52202 root    6u  IPv4 0xfffff80004ebc740      0t0    RAW *:*
php-fpm 52202 root    7u  sock                         0t0        no further information on family 0x20
php-fpm 52202 root    8u  unix 0xfffff80004d6da38      0t0        ->0xfffff80004d6d6d0
php-fpm 52202 root    9u  unix 0xfffff80004d6d6d0      0t0        ->0xfffff80004d6da38
php-fpm 52202 root   10r  VCHR                0,8      0t0      8 /dev/random
php-fpm 52202 root   11ur VREG               0,82        0 321026 / (/dev/ufsid/5f4fb11ba7c2e0ef)
php-fpm 52202 root   12u  unix 0xfffff8002edd6368      0t0        /var/run/php-fpm.socket
php-fpm 52202 root   13u  unix 0xfffff80004d6ca38      0t0        /var/run/php-fpm.socket
php-fpm 52202 root   14u  unix 0xfffff80009880368      0t0        ->0xfffff80009883368
php-fpm 52202 root   15w  VREG               0,82        0 321041 / (/dev/ufsid/5f4fb11ba7c2e0ef)
php-fpm 52202 root   16w  VREG               0,82        0 321049 / (/dev/ufsid/5f4fb11ba7c2e0ef)

top:

[2.4.5-RELEASE][admin@gw01]/root: top
last pid: 37556;  load averages: 12.57,  8.89,  6.36                                                                                                          up 67+16:23:49  09:35:51
88 processes:  2 running, 86 sleeping
CPU: 57.8% user,  0.0% nice, 19.1% system, 23.0% interrupt,  0.0% idle
Mem: 36M Active, 215M Inact, 291M Wired, 100M Buf, 399M Free
Swap: 768M Total, 768M Free

  PID USERNAME    THR PRI NICE   SIZE    RES STATE    TIME    WCPU COMMAND
52202 root          1  92    0 97044K 41148K RUN      5:21  59.65% php-fpm

Topogigio · Nov 9, 2020, 9:20 AM

also truss:

[2.4.5-RELEASE][admin@gw01]/root: truss -p 52202
accept(13,{ AF_UNIX "" },0x7ffffffee958)         = 12 (0xc)
poll({ 12/POLLIN },1,5000)                       = 1 (0x1)
getrusage(RUSAGE_SELF,{ u=391.610731,s=113.553168,in=0,out=2 }) = 0 (0x0)
getrusage(RUSAGE_CHILDREN,{ u=52.231295,s=67.120794,in=0,out=0 }) = 0 (0x0)
read(12,"\^A\^A\0\^A\0\b\0\0",8)                 = 8 (0x8)
read(12,"\0\^A\0\0\0\0\0\0",8)                   = 8 (0x8)
read(12,"\^A\^D\0\^A\0\M-C\0\0",8)               = 8 (0x8)
read(12,"\^Q\vGATEWAY_INTERFACEFastCGI/1."...,195) = 195 (0xc3)
read(12,"\^A\^D\0\^A\0\0\0\0",8)                 = 8 (0x8)
lstat("/etc/rc.expireaccounts",{ mode=-rwxr-xr-x ,inode=481667,size=1630,blksize=32768 }) = 0 (0x0)
lstat("/etc",{ mode=drwxr-xr-x ,inode=481536,size=4608,blksize=32768 }) = 0 (0x0)
sigprocmask(SIG_SETMASK,{ SIGHUP|SIGINT|SIGQUIT|SIGILL|SIGTRAP|SIGABRT|SIGEMT|SIGFPE|SIGKILL|SIGBUS|SIGSEGV|SIGSYS|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ }) = 0 (0x0)
sigaction(SIGPROF,0x0,{ 0x80170f200 SA_SIGINFO ss_t }) = 0 (0x0)
sigprocmask(SIG_SETMASK,{ },0x0)                 = 0 (0x0)
sigprocmask(SIG_SETMASK,{ SIGHUP|SIGINT|SIGQUIT|SIGILL|SIGTRAP|SIGABRT|SIGEMT|SIGFPE|SIGKILL|SIGBUS|SIGSEGV|SIGSYS|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ }) = 0 (0x0)
sigaction(SIGHUP,0x0,{ 0x80170f200 SA_SIGINFO ss_t }) = 0 (0x0)
sigprocmask(SIG_SETMASK,{ },0x0)                 = 0 (0x0)
sigprocmask(SIG_SETMASK,{ SIGHUP|SIGINT|SIGQUIT|SIGILL|SIGTRAP|SIGABRT|SIGEMT|SIGFPE|SIGKILL|SIGBUS|SIGSEGV|SIGSYS|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ }) = 0 (0x0)
sigaction(SIGINT,0x0,{ 0x80170f200 SA_SIGINFO ss_t }) = 0 (0x0)
sigprocmask(SIG_SETMASK,{ },0x0)                 = 0 (0x0)
sigprocmask(SIG_SETMASK,{ SIGHUP|SIGINT|SIGQUIT|SIGILL|SIGTRAP|SIGABRT|SIGEMT|SIGFPE|SIGKILL|SIGBUS|SIGSEGV|SIGSYS|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ }) = 0 (0x0)
sigaction(SIGQUIT,0x0,{ 0x80170f200 SA_SIGINFO ss_t }) = 0 (0x0)
sigprocmask(SIG_SETMASK,{ },0x0)                 = 0 (0x0)
sigprocmask(SIG_SETMASK,{ SIGHUP|SIGINT|SIGQUIT|SIGILL|SIGTRAP|SIGABRT|SIGEMT|SIGFPE|SIGKILL|SIGBUS|SIGSEGV|SIGSYS|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ }) = 0 (0x0)
sigaction(SIGTERM,0x0,{ 0x80170f200 SA_SIGINFO ss_t }) = 0 (0x0)
sigprocmask(SIG_SETMASK,{ },0x0)                 = 0 (0x0)
sigprocmask(SIG_SETMASK,{ SIGHUP|SIGINT|SIGQUIT|SIGILL|SIGTRAP|SIGABRT|SIGEMT|SIGFPE|SIGKILL|SIGBUS|SIGSEGV|SIGSYS|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ }) = 0 (0x0)
sigaction(SIGUSR1,0x0,{ 0x80170f200 SA_SIGINFO ss_t }) = 0 (0x0)
sigprocmask(SIG_SETMASK,{ },0x0)                 = 0 (0x0)
sigprocmask(SIG_SETMASK,{ SIGHUP|SIGINT|SIGQUIT|SIGILL|SIGTRAP|SIGABRT|SIGEMT|SIGFPE|SIGKILL|SIGBUS|SIGSEGV|SIGSYS|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ }) = 0 (0x0)
sigaction(SIGUSR2,0x0,{ 0x80170f200 SA_SIGINFO ss_t }) = 0 (0x0)
sigprocmask(SIG_SETMASK,{ },0x0)                 = 0 (0x0)
setitimer(2,{ 0.000000, 1800.000000 },0x0)       = 0 (0x0)
sigprocmask(SIG_SETMASK,{ SIGHUP|SIGINT|SIGQUIT|SIGILL|SIGTRAP|SIGABRT|SIGEMT|SIGFPE|SIGKILL|SIGBUS|SIGSEGV|SIGSYS|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ }) = 0 (0x0)
sigaction(SIGPROF,{ 0x80170f200 SA_SIGINFO ss_t },{ 0x80170f200 SA_SIGINFO ss_t }) = 0 (0x0)
sigprocmask(SIG_SETMASK,{ },0x0)                 = 0 (0x0)
sigprocmask(SIG_UNBLOCK,{ SIGPROF },0x0)         = 0 (0x0)
__getcwd("/var/run",4095)                        = 0 (0x0)
chdir("/etc")                                    = 0 (0x0)
setitimer(2,{ 0.000000, 900.000000 },0x0)        = 0 (0x0)
fcntl(11,F_SETLK,0x7fffffffd230)                 = 0 (0x0)
stat("/etc/rc.expireaccounts",{ mode=-rwxr-xr-x ,inode=481667,size=1630,blksize=32768 }) = 0 (0x0)
__getcwd("/etc",1024)                            = 0 (0x0)
lstat("/etc/version",{ mode=-rw-r--r-- ,inode=481605,size=14,blksize=32768 }) = 0 (0x0)
openat(AT_FDCWD,"/etc/version",O_RDONLY,00)      = 15 (0xf)
fstat(15,{ mode=-rw-r--r-- ,inode=481605,size=14,blksize=32768 }) = 0 (0x0)
lseek(15,0x0,SEEK_CUR)                           = 0 (0x0)
fstat(15,{ mode=-rw-r--r-- ,inode=481605,size=14,blksize=32768 }) = 0 (0x0)
read(15,"2.4.5-RELEASE\n",8192)                  = 14 (0xe)
read(15,0x802a71000,8192)                        = 0 (0x0)
read(15,0x802a71000,8192)                        = 0 (0x0)
close(15)                                        = 0 (0x0)
access("/etc/version.patch",F_OK)                = 0 (0x0)
lstat("/etc/version.patch",{ mode=-rw-r--r-- ,inode=481594,size=2,blksize=32768 }) = 0 (0x0)
openat(AT_FDCWD,"/etc/version.patch",O_RDONLY,00) = 15 (0xf)
fstat(15,{ mode=-rw-r--r-- ,inode=481594,size=2,blksize=32768 }) = 0 (0x0)
lseek(15,0x0,SEEK_CUR)                           = 0 (0x0)
fstat(15,{ mode=-rw-r--r-- ,inode=481594,size=2,blksize=32768 }) = 0 (0x0)
read(15,"1\n",8192)                              = 2 (0x2)
read(15,0x802a78000,8192)                        = 0 (0x0)
read(15,0x802a78000,8192)                        = 0 (0x0)
close(15)                                        = 0 (0x0)
access("/etc/default-config-flavor",F_OK)        = 0 (0x0)
lstat("/etc/default-config-flavor",{ mode=-rw-r--r-- ,inode=481692,size=1,blksize=32768 }) = 0 (0x0)
openat(AT_FDCWD,"/etc/default-config-flavor",O_RDONLY,00) = 15 (0xf)
fstat(15,{ mode=-rw-r--r-- ,inode=481692,size=1,blksize=32768 }) = 0 (0x0)
lseek(15,0x0,SEEK_CUR)                           = 0 (0x0)
fstat(15,{ mode=-rw-r--r-- ,inode=481692,size=1,blksize=32768 }) = 0 (0x0)
read(15,"\n",8192)                               = 1 (0x1)
read(15,0x802a78000,8192)                        = 0 (0x0)
read(15,0x802a78000,8192)                        = 0 (0x0)
close(15)                                        = 0 (0x0)
__sysctl(0x7fffffffcb68,0x2,0x7fffffffcbb0,0x7fffffffcb60,0x0,0x0) = 0 (0x0)
__sysctl(0x7fffffffcb68,0x2,0x7fffffffccb0,0x7fffffffcb60,0x0,0x0) = 0 (0x0)
__sysctl(0x7fffffffcb68,0x2,0x7fffffffcdb0,0x7fffffffcb60,0x0,0x0) = 0 (0x0)
__sysctl(0x7fffffffcb68,0x2,0x7fffffffceb0,0x7fffffffcb60,0x0,0x0) = 0 (0x0)
__sysctl(0x7fffffffcb68,0x2,0x7fffffffcfb0,0x7fffffffcb60,0x0,0x0) = 0 (0x0)
access("/etc/inc/globals_override.inc",F_OK)     ERR#2 'No such file or directory'
access("/cf/conf/enableserial_force",F_OK)       ERR#2 'No such file or directory'
__sysctl(0x7fffffffcb68,0x2,0x7fffffffcbb0,0x7fffffffcb60,0x0,0x0) = 0 (0x0)
__sysctl(0x7fffffffcb68,0x2,0x7fffffffccb0,0x7fffffffcb60,0x0,0x0) = 0 (0x0)
__sysctl(0x7fffffffcb68,0x2,0x7fffffffcdb0,0x7fffffffcb60,0x0,0x0) = 0 (0x0)
__sysctl(0x7fffffffcb68,0x2,0x7fffffffceb0,0x7fffffffcb60,0x0,0x0) = 0 (0x0)
__sysctl(0x7fffffffcb68,0x2,0x7fffffffcfb0,0x7fffffffcb60,0x0,0x0) = 0 (0x0)
access("/cf/conf/use_xmlreader",F_OK)            ERR#2 'No such file or directory'
access("/debugging",F_OK)                        ERR#2 'No such file or directory'
access("/var/run/booting",F_OK)                  ERR#2 'No such file or directory'
access("/tmp/config.lock",F_OK)                  = 0 (0x0)
lstat("/tmp/config.lock",{ mode=-rw-rw-rw- ,inode=321028,size=0,blksize=32768 }) = 0 (0x0)
lstat("/tmp",{ mode=drwxrwxrwt ,inode=321024,size=2048,blksize=32768 }) = 0 (0x0)
openat(AT_FDCWD,"/tmp/config.lock",O_WRONLY|O_CREAT|O_TRUNC,0666) = 15 (0xf)
fstat(15,{ mode=-rw-rw-rw- ,inode=321028,size=0,blksize=32768 }) = 0 (0x0)
lseek(15,0x0,SEEK_CUR)                           = 0 (0x0)
flock(15,LOCK_SH)                                = 0 (0x0)
access("/conf/config.xml",F_OK)                  = 0 (0x0)
stat("/conf/config.xml",{ mode=-rw-r--r-- ,inode=1284133,size=228319,blksize=32768 }) = 0 (0x0)
access("/var/run/booting",F_OK)                  ERR#2 'No such file or directory'
access("/conf/config.xml",F_OK)                  = 0 (0x0)
access("/var/run/booting",F_OK)                  ERR#2 'No such file or directory'
access("/tmp/config.cache",F_OK)                 = 0 (0x0)
lstat("/tmp/config.cache",{ mode=-rw-r--r-- ,inode=321092,size=199160,blksize=32768 }) = 0 (0x0)
openat(AT_FDCWD,"/tmp/config.cache",O_RDONLY,00) = 16 (0x10)
fstat(16,{ mode=-rw-r--r-- ,inode=321092,size=199160,blksize=32768 }) = 0 (0x0)
lseek(16,0x0,SEEK_CUR)                           = 0 (0x0)
fstat(16,{ mode=-rw-r--r-- ,inode=321092,size=199160,blksize=32768 }) = 0 (0x0)
read(16,"a:33:{s:7:"version";s:4:"19.1";s"...,8192) = 8192 (0x2000)
read(16,"VPNCX02_1_F01_1_LANs";s:7:"gate"...,8192) = 8192 (0x2000)
read(16,"p";s:6:"target";s:7:"R51_LAN";s:"...,8192) = 8192 (0x2000)
read(16,"";s:5:"descr";s:14:"R58 HTTP-HTT"...,8192) = 8192 (0x2000)
read(16,"created";a:2:{s:4:"time";s:10:"1"...,8192) = 8192 (0x2000)
read(16,"te_Subnets";s:3:"not";s:0:"";s:4"...,8192) = 8192 (0x2000)
read(16,"89.186.81.246 (Local Database)";"...,8192) = 8192 (0x2000)
read(16,"ss";s:8:"NG02_LAN";s:4:"port";s:"...,8192) = 8192 (0x2000)
read(16,"";s:8:"protocol";s:4:"icmp";s:8:"...,8192) = 8192 (0x2000)
read(16,"x-src-states";s:0:"";s:12:"state"...,8192) = 8192 (0x2000)
read(16,"s:10:"encryption";a:1:{s:4:"item"...,8192) = 8192 (0x2000)
read(16,"3:"256";}s:14:"hash-algorithm";s"...,8192) = 8192 (0x2000)
read(16,"s:21:"authentication_method";s:1"...,8192) = 8192 (0x2000)
read(16,"alid";a:2:{s:4:"type";s:7:"addre"...,8192) = 8192 (0x2000)
read(16,"5:"reqid";s:2:"20";s:7:"localid""...,8192) = 8192 (0x2000)
read(16,"00 8001 8002";s:5:"descr";s:0:"""...,8192) = 8192 (0x2000)
read(16,"added Mon, 07 Sep 2020 15:38:25 "...,8192) = 8192 (0x2000)
read(16,"ded Mon, 07 Sep 2020 15:38:25 +0"...,8192) = 8192 (0x2000)
read(16,""detail";s:8:"MacroLAN";}i:64;a:"...,8192) = 8192 (0x2000)
read(16,"Rc0ZBREJhTVRnd05nWURWUVFLRXk5d1p"...,8192) = 8192 (0x2000)
read(16,"Z1FETUJUU3k1alhGVzZxNDNGMExJSjlT"...,8192) = 8192 (0x2000)
read(16,"3:"HAProxy Stats";s:11:"tooltipt"...,8192) = 8192 (0x2000)
read(16,"6:"action";s:6:"permit";s:6:"sou"...,8192) = 8192 (0x2000)
read(16,":0:"";s:11:"stats_realm";s:0:"";"...,8192) = 8192 (0x2000)
read(16,"lISUVjTjBGKytnSVNOWHB0ekRQVHF6WU"...,8192) = 2552 (0x9f8)
read(16,0x802ae4000,8192)                        = 0 (0x0)
read(16,0x802ae4000,8192)                        = 0 (0x0)
close(16)                                        = 0 (0x0)
access("/var/run/booting",F_OK)                  ERR#2 'No such file or directory'
flock(15,LOCK_UN)                                = 0 (0x0)
close(15)                                        = 0 (0x0)
stat("/usr/local/pkg/parse_config",0x7fffffffd068) ERR#2 'No such file or directory'
write(12,"\^A\^F\0\^A\0\^B\^F\0001\n\0\0\0"...,16) = 16 (0x10)
write(12,"\^A\^F\0\^A\0\^R\^F\0User baz ex"...,32) = 32 (0x20)
write(12,"\^A\^F\0\^A\0\^B\^F\0001\n\0\0\0"...,16) = 16 (0x10)
write(12,"\^A\^F\0\^A\0\^Q\a\0User sl expi"...,32) = 32 (0x20)
chdir("/var/run")                                = 0 (0x0)
getrusage(RUSAGE_SELF,{ u=391.613602,s=113.758816,in=0,out=2 }) = 0 (0x0)
getrusage(RUSAGE_CHILDREN,{ u=52.231295,s=67.120794,in=0,out=0 }) = 0 (0x0)
setitimer(2,{ 0.000000, 0.000000 },0x0)          = 0 (0x0)
fcntl(11,F_SETLK,0x7fffffffe890)                 = 0 (0x0)
write(12,"\^A\^C\0\^A\0\b\0\0\0\0\0\0\0sl ",16)  = 16 (0x10)
shutdown(12,SHUT_WR)                             ERR#57 'Socket is not connected'
recvfrom(12,"\^A\^E\0\^A\0\0\0\0",8,0,NULL,0x0)  = 8 (0x8)
recvfrom(12,0x7fffffffa848,8,0,NULL,0x0)         = 0 (0x0)
close(12)                                        = 0 (0x0)
setitimer(2,{ 0.000000, 0.000000 },0x0)          = 0 (0x0)

kiokoman · Nov 9, 2020, 9:53 AM

it is checking for an expired account and after that I see haproxy stats
maybe try to temporarily disable haproxy stats

Leave this setting empty to remove the "HAProxyLocalStats" item from the stats page and save a little on recources.

Topogigio · Nov 9, 2020, 10:09 AM

@kiokoman it seems strange: HA proxy is disabled. The "Enable HAProxy" flag is disabled.

Now I've uninstalled it to be sure: "pfSense-pkg-haproxy removal successfully completed."
Still php-fpn processes are eating cpu.

Also I cannot find expired accounts :( How can I find id?

Topogigio · Nov 9, 2020, 10:27 AM

I did run truss an other time, and now output is a 40MB of log (full of private data).. :(

errors I see:
access("/tmp/ipsec16000_defaultgw",F_OK) ERR#2 'No such file or directory'
access("/tmp/ipsec17000_defaultgw",F_OK) ERR#2 'No such file or directory'
access("/tmp/ipsec18000_defaultgw",F_OK) ERR#2 'No such file or directory'
access("/tmp/ipsec26000_defaultgw",F_OK) ERR#2 'No such file or directory'

etc..

fcntl(18,F_GETFD,) ERR#9 'Bad file descriptor'

kiokoman · Nov 9, 2020, 10:46 AM

it was checking for an expired account, it does not mean that there are any...
I think it's under system / user account

nothing useful inside Status / System Logs / IPsec ?

hopefully, someone will chime in on this I have no idea, I don't use that many IPsec but I don't think that only 25 IPsec is a problem

maybe that "no such file" are the culprit
go inside any ipsec and just press "save" and see if they are generated

Topogigio · Nov 9, 2020, 11:14 AM

@kiokoman I tried to check it from the OS: files exist, and seems recreated all at the same time (now), eg

11 Nov 9 11:31 ipsec10000_router

they are all 11 bytes long.

I cannot paste full output because Askimet blocks me :(

kiokoman · Nov 11, 2020, 6:43 PM

if you can, disable ipsec tunnel one by one until you find what is causing the problem