Due to rate limiting by rsyslog, /var/log/messages is showing lots of dropped message entries:
... Nov 7 14:23:14 thx1138 rsyslogd-2177: imuxsock lost 516 messages from pid 159386 due to rate-limiting Nov 7 14:23:15 thx1138 rsyslogd-2177: imuxsock begins to drop messages from pid 159386 due to rate-limiting Nov 7 14:23:20 thx1138 rsyslogd-2177: imuxsock lost 512 messages from pid 159386 due to rate-limiting Nov 7 14:23:21 thx1138 rsyslogd-2177: imuxsock begins to drop messages from pid 159386 due to rate-limiting Nov 7 14:29:50 thx1138 rsyslogd-2177: imuxsock begins to drop messages from pid 238300 due to rate-limiting ...
This is expected behavior. rsyslogd is working correctly. The entries regarding dropped messages are normal entries. By default, rsyslogd accepts 200 messages in 5 seconds from a single process. If that threshold is exceeded, messages will be dropped. So in the case of the example entry below process 77845 sent about 436 messages in a 5 second period. Due to rate limiting, rsyslogd dropped 236 of those.
... Nov 6 15:46:48 thx1138 rsyslogd-2177: imuxsock begins to drop messages from pid 77845 due to rate-limiting Nov 6 15:46:52 thx1138 rsyslogd-2177: imuxsock lost 236 messages from pid 77845 due to rate-limiting PID 77845 ...
Setting the following parameters with the values shown below will disable rate limiting and no messages will be dropped.
# vi /etc/rsyslog.conf $SystemLogRateLimitInterval 0 $SystemLogRateLimitBurst 0 $IMUXSockRateLimitBurst 0 $IMUXSockRateLimitInterval 0 $IMUXSockRateLimitSeverity 7 ...
One may expect every entry handled by rsyslog will be entered into the messages file. This is not the case. The rsyslog.conf file has a section called RULES that governs where rsyslog writes the messages. By default, only kernel messages, informational messages, and emergency messages are written to the messages file. Other messages are written to other files. For example, messages dealing with user authentication go to /var/log/secure and messages dealing with mail go to /var/log/maillog.
Because rsyslog writes messages to different files based on their type, turning off rate limiting will cause all messages to be written to their designated log files, not just the messages file. You can see this in action by doing the following:
1. Make a backup of your /etc/rsyslogd.conf file.
# cp -p /etc/rsyslog.conf /etc/rsyslog.conf_orig
2. Disable rate-limiting as detailed in shown in the post below depending on your OS version.
How To Disable Or Extend System Logging Rate-limit on CentOS/RHEL 7
3. Make note of the size of the log files in /var/log:
# ls -la /var/log
4. Restart rsyslog.
# service rsyslog restart ### CentOS/RHEL 6 # systemctl restart rsyslog ### CentOS/RHEL 7
5. Wait for about 1 hour.
6. Revert the changes made in step 2.
7. Restart rsyslog.
# service rsyslog restart ### CentOS/RHEL 6 # systemctl restart rsyslog ### CentOS/RHEL 7
8. Note the sizes of the log files in /var/log.
The results of this will be that:
- The sizes of one or more of the log files other than the messages file in /var/log grew greatly.
- The entries in one or more of the log files increased in frequency during the time rate-limiting was disabled.
- Few if any entries were seen in the messages file. As seen in this example, messages were being dropped until rate-limiting was disabled and rsyslog restarted at 14:30. Between 14:30 and 15:33 there is only one entry for rngd at 14:44. After enabling rate limiting, the dropped messages begin again.
Nov 7 14:23:21 thx1138 rsyslogd-2177: imuxsock begins to drop messages from pid 159386 due to rate-limiting Nov 7 14:29:50 thx1138 rsyslogd-2177: imuxsock begins to drop messages from pid 238300 due to rate-limiting Nov 7 14:30:02 thx1138 kernel: Kernel logging (proc) stopped. Nov 7 14:30:02 thx1138 rsyslogd: [origin software="rsyslogd" swVersion="5.8.10" x-pid="13439" x-info="http://www.rsyslog.com"] exiting on signal 15. Nov 7 14:30:02 thx1138 kernel: imklog 5.8.10, log source = /proc/kmsg started. Nov 7 14:30:02 thx1138 rsyslogd: [origin software="rsyslogd" swVersion="5.8.10" x-pid="242406" x-info="http://www.rsyslog.com"] start Nov 7 14:44:15 thx1138 rngd[13453]: read error Nov 7 15:32:58 thx1138 kernel: Kernel logging (proc) stopped. Nov 7 15:32:58 thx1138 rsyslogd: [origin software="rsyslogd" swVersion="5.8.10" x-pid="242406" x-info="http://www.rsyslog.com"] exiting on signal 15. Nov 7 15:32:59 thx1138 kernel: imklog 5.8.10, log source = /proc/kmsg started. Nov 7 15:32:59 thx1138 rsyslogd: [origin software="rsyslogd" swVersion="5.8.10" x-pid="175797" x-info="http://www.rsyslog.com"] start Nov 7 15:34:25 thx1138 rsyslogd-2177: imuxsock begins to drop messages from pid 179680 due to rate-limiting Nov 7 15:35:56 thx1138 rsyslogd-2177: imuxsock lost 193 messages from pid 179680 due to rate-limiting
So from the above, we can see that disabling rate limiting is actually working, just not as one may expect it to work. The following must be considered in regards to rate limiting:
1. A random and infrequent burst of messages is not necessarily an indication of a problem. However, a continued sustained repeat of dropped messages may be investigated. If dropped messages are occurring frequently and there are large numbers being dropped, then an investigation into what these messages are (informational or actual warnings of errors) is needed. You can use the test above to see where the messages are going then review the logs in /var/log to determine if a problem really exists or note.
2. Be careful in changing the rate limit settings in rsyslogd.conf or disabling rate-limiting altogether. The fewer messages that are dropped means the more processing that is required to log them. Too many messages can cause performance issues and in extreme circumstances even evictions.