> From: Alex Rousskov <rousskov@xxxxxxxxxxxxxxxxxxxxxxx> > >> # cat /etc/security/limits.d/01_squid.conf >> * hard nofile 65535 >> * soft nofile 16384 > > Your Squid does not know about the above configured limits. It thinks the limit is 1024. That's interesting. # grep "file descriptors available" cache.log 2017/10/24 11:49:33 kid1| With 1024 file descriptors available 2017/10/24 12:57:10 kid1| With 16384 file descriptors available 2017/10/24 12:57:52 kid1| With 16384 file descriptors available 2017/10/25 05:50:32 kid1| With 1024 file descriptors available 2017/10/25 09:20:15 kid1| With 1024 file descriptors available 2017/10/25 10:00:15 kid1| With 1024 file descriptors available 2017/10/25 12:00:15 kid1| With 1024 file descriptors available 2017/10/25 13:00:16 kid1| With 1024 file descriptors available 2017/10/25 13:20:16 kid1| With 1024 file descriptors available 2017/10/25 14:00:15 kid1| With 1024 file descriptors available 2017/10/26 04:09:30 kid1| With 1024 file descriptors available 2017/10/26 10:57:45 kid1| With 16384 file descriptors available The issues I reported yesterday came up after 2017/10/26 04:09:30, so here's the relevant part in the log: 2017/10/26 04:09:27 kid1| Reconfiguring Squid Cache (version 3.5.27-20170916-re69e56c)... 2017/10/26 04:09:27 kid1| Closing HTTP port [::]:3128 2017/10/26 04:09:27 kid1| Closing HTTP port [::]:3129 2017/10/26 04:09:27 kid1| Closing HTTPS port [::]:3130 2017/10/26 04:09:27 kid1| Closing Pinger socket on FD 801 2017/10/26 04:09:27 kid1| Logfile: closing log daemon:/var/log/squid/access.log 2017/10/26 04:09:27 kid1| Logfile Daemon: closing log daemon:/var/log/squid/access.log 2017/10/26 04:09:27 kid1| FATAL: dying from an unhandled exception: IsConnOpen(conn) 2017/10/26 04:09:30| Pinger exiting. 2017/10/26 04:09:30 kid1| Set Current Directory to /var/cache/squid 2017/10/26 04:09:30 kid1| Starting Squid Cache version 3.5.27-20170916-re69e56c for x86_64-pc-linux-gnu... 2017/10/26 04:09:30 kid1| Service Name: squid 2017/10/26 04:09:30 kid1| Process ID 22581 2017/10/26 04:09:30 kid1| Process Roles: worker 2017/10/26 04:09:30 kid1| With 1024 file descriptors available A "reload" was issued at that time. When my openrc init script reloads, it runs the following command: # /etc/init.d/squid reload * Reloading squid with /usr/sbin/squid -k reconfigure -f /etc/squid/squid.conf -n squid ... [ ok ] I issued another "reload" today, and I didn't come up with any "file descriptors available" messages in cache.log (as expected). I also checked mgr:info, and all seems OK: File descriptor usage for squid: Maximum number of file descriptors: 16384 Largest file desc currently in use: 3067 Number of file desc currently in use: 2901 Files queued for open: 0 Available number of file descriptors: 13483 Reserved number of file descriptors: 100 Store Disk files open: 0 I also grep'ed for the log lines around "2017/10/25 05:50:32 kid1| With 1024 file descriptors available" where I see 1024 file descriptors for the first time. It was a clean restart (with no "FATAL" error message). The "restart" command was launched from crontab as a daily job (calling the openrc init script) just like it is launched at boot time from openrc (when the number of file descriptors is "as expected"). In particular, I have: KRB5_KTNAME="/etc/krb5.keytab" /usr/sbin/squid -YC -f /etc/squid/squid.conf -n squid I'm wondering why Squid only detected 1024 file descriptors available after that restart. Moving back in time: - "2017/10/24 12:57:52 kid1| With 16384 file descriptors available" was probably a manual restart on my behalf (passing "restart" to the init script on the console). - the one right before (2017/10/24 12:57:10) was probably also a manual restart as the init script probably exited non-zero due to an error I found in the log: "FATAL: dying from an unhandled exception: IsConnOpen(conn)" - moving back a little (11:49:30), I had a "reload" with a fatal error: 2017/10/24 11:49:30.406 kid1| Reconfiguring Squid Cache (version 3.5.27-20170916-re69e56c)... 2017/10/24 11:49:30.406 kid1| Closing HTTP port [::]:3128 2017/10/24 11:49:30.406 kid1| Closing HTTP port [::]:3129 2017/10/24 11:49:30.406 kid1| Closing HTTPS port [::]:3130 2017/10/24 11:49:30.406 kid1| Closing Pinger socket on FD 788 2017/10/24 11:49:30.406 kid1| Logfile: closing log daemon:/var/log/squid/access.log 2017/10/24 11:49:30.406 kid1| Logfile Daemon: closing log daemon:/var/log/squid/access.log 2017/10/24 11:49:30.406 kid1| FATAL: dying from an unhandled exception: IsConnOpen(conn) 2017/10/24 11:49:33 kid1| Set Current Directory to /var/cache/squid 2017/10/24 11:49:33 kid1| Starting Squid Cache version 3.5.27-20170916-re69e56c for x86_64-pc-linux-gnu... 2017/10/24 11:49:33 kid1| Service Name: squid 2017/10/24 11:49:33 kid1| Process ID 30753 2017/10/24 11:49:33 kid1| Process Roles: worker 2017/10/24 11:49:33 kid1| With 1024 file descriptors available - searching within the older rotated cache.log files I noticed this: 2017/10/20 10:42:12 kid1| With 16384 file descriptors available 2017/10/21 05:50:32 kid1| With 1024 file descriptors available The restart at 05:50:32 is performed by a cron job. Conclusion: it seems that the cron daemon I use (https://github.com/cronie-crond/cronie) is not honoring system-wide ulimits defined in /etc/security/limits.d/* as, eg.: * hard nofile 65535 * soft nofile 16384 Weird. I'm not going to be using the cron job anymore. Thanks, Vieri _______________________________________________ squid-users mailing list squid-users@xxxxxxxxxxxxxxxxxxxxx http://lists.squid-cache.org/listinfo/squid-users
