How can i can determine if rsyslog is dropping msgs?

General discussions here

Moderator: rgerhards

Google Ads


How can i can determine if rsyslog is dropping msgs?

Postby a212830 » Fri Apr 28, 2017 11:30 pm

Hi,

We use rsyslog to write network syslogs and then route to Splunk. It appears, based upon some tcpdump analysis, that rsyslog is dropping mgs, though I haven't confirmed that on my end yet. Are there any stats or way to show if msgs are being dropped, or even how it's performing? We are running rsyslog 5.8.10, on OEL.

Thanks.
a212830
Avarage
 
Posts: 12
Joined: Wed Jan 09, 2013 11:54 pm

Urgent Question?

  • Pulling out your Hair?
  • Wasting Time and Money?
  • Deadline Approaching?

Re: How can i can determine if rsyslog is dropping msgs?

Postby dlang » Fri Apr 28, 2017 11:36 pm

unless you explicitly tell it to, rsyslog will not knowingly drop messages.

That said, if you are using UDP and you can't keep up with the incoming messages for some reason, messages can be lost.

If rsyslog cannot deliver messages to the destination fast enough, it will fill it's internal queues and stop processing messages, you can see this via the output of the impstats module.

But this doesn't tell you what (if anything) was dropped, just that it's got full queues.

The OS maintains a queue for UDP sockets, and it has stats of dropped UDP packets, you can monitor that.

But properly configured, rsyslog is able to keep up with very high message rates (hundreds of thousands of logs/sec), so if you are dropping messages for anything other than outputs not being able to keep up, give us more details of what you've got configured and we should be able to help you improve things.

newer versions are much better than old ones, the current version is 8.26 or so
dlang
Frequent Poster
 
Posts: 1001
Joined: Mon Sep 15, 2008 7:44 am

Re: How can i can determine if rsyslog is dropping msgs?

Postby a212830 » Fri Apr 28, 2017 11:40 pm

Thanks. Unfortunately, the version is determined by the server support team, and I have to live with it.

Here's my config:

Code: Select all
# rsyslog v5 configuration file

# For more information see /usr/share/doc/rsyslog-*/rsyslog_conf.html
# If you experience problems, see http://www.rsyslog.com/doc/troubleshoot.html

#### MODULES ####

$ModLoad imuxsock # provides support for local system logging (e.g. via logger command)
$ModLoad imklog   # provides kernel logging support (previously done by rklogd)
#$ModLoad immark  # provides --MARK-- message capability

# Provides UDP syslog reception
$ModLoad imudp
$UDPServerRun 514

$IncludeConfig /export/home/splunk/rsyslog.d/loglogic.conf

# Provides TCP syslog reception
#$ModLoad imtcp
#$InputTCPServerRun 514


#### GLOBAL DIRECTIVES ####

# Use default timestamp format
$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat

# File syncing capability is disabled by default. This feature is usually not required,
# not useful and an extreme performance hit
#$ActionFileEnableSync on

# Include all config files in /etc/rsyslog.d/
$IncludeConfig /etc/rsyslog.d/*.conf


#### RULES ####

:fromhost-ip , !isequal , "127.0.0.1" ~


# Log all kernel messages to the console.
# Logging much else clutters up the screen.
#kern.*                                                 /dev/console
kern.crit                                               /var/log/messages

# Log anything (except mail) of level info or higher.
# Don't log private authentication messages!
*.info;mail.none;authpriv.none;cron.none                /var/log/messages

# The authpriv file has restricted access.
authpriv.*                                              /var/log/secure

# Log all the mail messages in one place.
mail.*                                                  -/var/log/maillog


# Log cron stuff
cron.*                                                  /var/log/cron

# Everybody gets emergency messages
*.emerg                                                 *

# Save news errors of level crit and higher in a special file.
uucp,news.crit                                          /var/log/spooler

# Save boot messages also to boot.log
local7.*                                                /var/log/boot.log


# ### begin forwarding rule ###
# The statement between the begin ... end define a SINGLE forwarding
# rule. They belong together, do NOT split them. If you create multiple
# forwarding rules, duplicate the whole block!
# Remote Logging (we use TCP for reliable delivery)
#
# An on-disk queue is created for this action. If the remote host is
# down, messages are spooled to disk and sent when it is up again.
#$WorkDirectory /var/lib/rsyslog # where to place spool files
#$ActionQueueFileName fwdRule1 # unique name prefix for spool files
#$ActionQueueMaxDiskSpace 1g   # 1gb space limit (use as much as possible)
#$ActionQueueSaveOnShutdown on # save messages to disk on shutdown
#$ActionQueueType LinkedList   # run asynchronously
#$ActionResumeRetryCount -1    # infinite retries if host is down
# remote host is: name/ip:port, e.g. 192.168.0.1:514, port optional
#*.* @@remote-host:514
# ### end of the forwarding rule ###


And here's a .conf file that is called:

Code: Select all
$umask 0000
# $template DynaFile,"/apps/logs/%$YEAR%/%$MONTH%/%$DAY%/system-%HOSTNAME%.log"
$template DynaFile,"/apps/logs/%$YEAR%/%$MONTH%/%$DAY%/system-%fromhost%.log"
# # $template DynaFile,"/apps/logs/%$YEAR%/%$MONTH%/%$DAY%/system-%syslogseverity-text%-%from
host%.log
$FileOwner splunk
$FileGroup splunk
$FileCreateMode 0755
$DirOwner splunk
$DirGroup splunk
$DirCreateMode 0755
*.* -?DynaFile
a212830
Avarage
 
Posts: 12
Joined: Wed Jan 09, 2013 11:54 pm

Re: How can i can determine if rsyslog is dropping msgs?

Postby dlang » Sat Apr 29, 2017 12:02 am

without having any stats from impstats, it's hard to know what's happening.

since you are using dynafiles, make sure your dynafilecachesize is set to some number higher than the number of files you are writing to (that is a crippling factor if it's set too low)

the improvements since 5.x are gigantic, you really should request that they upgrade the package to something closer to current. RHEL has a 7.x version available in their backports repo. While that's still old, it's not nearly as ancient as 5.x
dlang
Frequent Poster
 
Posts: 1001
Joined: Mon Sep 15, 2008 7:44 am

Re: How can i can determine if rsyslog is dropping msgs?

Postby a212830 » Sat Apr 29, 2017 12:12 am

Thanks. I'll try to get some stats from impstats. I've tried many times to get them to upgrade the rsyslog version, but they won't do it. The answer is to swap out my server and upgrade to RH7, which is a major pita.
a212830
Avarage
 
Posts: 12
Joined: Wed Jan 09, 2013 11:54 pm

Re: How can i can determine if rsyslog is dropping msgs?

Postby a212830 » Sat Apr 29, 2017 3:12 am

Here's some output from impstats:

[root@vlrtp69 ~]# tail -f /apps/logs/rsyslog-stats
2017-04-28T21:49:25.739587-04:00 vlrtp69 rsyslogd-pstats: imuxsock: submitted=172 ratelimit.discarded=0 ratelimit.numratelimiters=67
2017-04-28T21:49:25.739598-04:00 vlrtp69 rsyslogd-pstats: main Q: size=1 enqueued=10165830 full=0 maxqsize=276
2017-04-28T21:54:25.779090-04:00 vlrtp69 rsyslogd-pstats: imuxsock: submitted=192 ratelimit.discarded=0 ratelimit.numratelimiters=79
2017-04-28T21:54:25.779107-04:00 vlrtp69 rsyslogd-pstats: main Q: size=1 enqueued=11906094 full=0 maxqsize=276
2017-04-28T21:59:25.878614-04:00 vlrtp69 rsyslogd-pstats: imuxsock: submitted=201 ratelimit.discarded=0 ratelimit.numratelimiters=88
2017-04-28T21:59:25.878619-04:00 vlrtp69 rsyslogd-pstats: main Q: size=1 enqueued=13633000 full=0 maxqsize=276
2017-04-28T22:04:25.978623-04:00 vlrtp69 rsyslogd-pstats: imuxsock: submitted=271 ratelimit.discarded=0 ratelimit.numratelimiters=106
2017-04-28T22:04:25.978633-04:00 vlrtp69 rsyslogd-pstats: main Q: size=1 enqueued=15748818 full=0 maxqsize=604
2017-04-28T22:09:26.078628-04:00 vlrtp69 rsyslogd-pstats: imuxsock: submitted=281 ratelimit.discarded=0 ratelimit.numratelimiters=116
2017-04-28T22:09:26.078637-04:00 vlrtp69 rsyslogd-pstats: main Q: size=1 enqueued=17879581 full=0 maxqsize=604
a212830
Avarage
 
Posts: 12
Joined: Wed Jan 09, 2013 11:54 pm

Re: How can i can determine if rsyslog is dropping msgs?

Postby a212830 » Sat Apr 29, 2017 3:15 am

And here are others:

[root@vlrtp71 ~]# tail -f /apps/logs/rsyslog-stats
2017-04-28T21:49:52.146248-04:00 vlrtp71 rsyslogd-pstats: imuxsock: submitted=156 ratelimit.discarded=0 ratelimit.numratelimiters=62
2017-04-28T21:49:52.146251-04:00 vlrtp71 rsyslogd-pstats: main Q: size=3 enqueued=17355914 full=0 maxqsize=1704
2017-04-28T21:54:52.246279-04:00 vlrtp71 rsyslogd-pstats: imuxsock: submitted=195 ratelimit.discarded=0 ratelimit.numratelimiters=74
2017-04-28T21:54:52.246288-04:00 vlrtp71 rsyslogd-pstats: main Q: size=1 enqueued=20130324 full=0 maxqsize=1704
2017-04-28T21:59:52.346257-04:00 vlrtp71 rsyslogd-pstats: imuxsock: submitted=236 ratelimit.discarded=0 ratelimit.numratelimiters=96
2017-04-28T21:59:52.346261-04:00 vlrtp71 rsyslogd-pstats: main Q: size=3 enqueued=23394179 full=0 maxqsize=1704
2017-04-28T22:04:52.446296-04:00 vlrtp71 rsyslogd-pstats: imuxsock: submitted=271 ratelimit.discarded=0 ratelimit.numratelimiters=111
2017-04-28T22:04:52.446311-04:00 vlrtp71 rsyslogd-pstats: main Q: size=1 enqueued=26634275 full=0 maxqsize=1704
2017-04-28T22:09:52.546339-04:00 vlrtp71 rsyslogd-pstats: imuxsock: submitted=279 ratelimit.discarded=0 ratelimit.numratelimiters=119
2017-04-28T22:09:52.546343-04:00 vlrtp71 rsyslogd-pstats: main Q: size=5 enqueued=29726243 full=0 maxqsize=1704
2017-04-28T22:14:52.646395-04:00 vlrtp71 rsyslogd-pstats: imuxsock: submitted=330 ratelimit.discarded=0 ratelimit.numratelimiters=138
2017-04-28T22:14:52.646405-04:00 vlrtp71 rsyslogd-pstats: main Q: size=1 enqueued=33877840 full=0 maxqsize=1704

--------------

[root@vlrtp877 ~]# tail -f /apps/logs/rsyslog-stats
2017-04-28T21:50:14.974214-04:00 VLRTP877 rsyslogd-pstats: imuxsock: submitted=221 ratelimit.discarded=0 ratelimit.numratelimiters=55
2017-04-28T21:50:14.974228-04:00 VLRTP877 rsyslogd-pstats: main Q: size=1 enqueued=1176622 full=0 maxqsize=152
2017-04-28T21:55:15.074257-04:00 VLRTP877 rsyslogd-pstats: imuxsock: submitted=267 ratelimit.discarded=0 ratelimit.numratelimiters=65
2017-04-28T21:55:15.074272-04:00 VLRTP877 rsyslogd-pstats: main Q: size=1 enqueued=1364252 full=0 maxqsize=152
2017-04-28T22:00:15.127459-04:00 VLRTP877 rsyslogd-pstats: imuxsock: submitted=428 ratelimit.discarded=0 ratelimit.numratelimiters=75
2017-04-28T22:00:15.127473-04:00 VLRTP877 rsyslogd-pstats: main Q: size=1 enqueued=1564923 full=0 maxqsize=152
2017-04-28T22:05:15.168238-04:00 VLRTP877 rsyslogd-pstats: imuxsock: submitted=484 ratelimit.discarded=0 ratelimit.numratelimiters=89
2017-04-28T22:05:15.168248-04:00 VLRTP877 rsyslogd-pstats: main Q: size=1 enqueued=1777855 full=0 maxqsize=152
2017-04-28T22:10:15.247183-04:00 VLRTP877 rsyslogd-pstats: imuxsock: submitted=492 ratelimit.discarded=0 ratelimit.numratelimiters=97
2017-04-28T22:10:15.247192-04:00 VLRTP877 rsyslogd-pstats: main Q: size=1 enqueued=2009518 full=0 maxqsize=152

--------------------------
2017-04-28T21:38:31.090592-04:00 vlrtp401 rsyslogd-pstats: main Q: size=9969 enqueued=661081 full=20312 maxqsize=10000
2017-04-28T21:43:31.190130-04:00 vlrtp401 rsyslogd-pstats: imuxsock: submitted=85 ratelimit.discarded=0 ratelimit.numratelimiters=64
2017-04-28T21:43:31.291082-04:00 vlrtp401 rsyslogd-pstats: main Q: size=9969 enqueued=790201 full=24347 maxqsize=10000
2017-04-28T21:48:31.390136-04:00 vlrtp401 rsyslogd-pstats: imuxsock: submitted=93 ratelimit.discarded=0 ratelimit.numratelimiters=72
2017-04-28T21:48:31.479208-04:00 vlrtp401 rsyslogd-pstats: main Q: size=9969 enqueued=920665 full=28424 maxqsize=10000
2017-04-28T21:53:31.579138-04:00 vlrtp401 rsyslogd-pstats: imuxsock: submitted=109 ratelimit.discarded=0 ratelimit.numratelimiters=84
2017-04-28T21:53:31.705200-04:00 vlrtp401 rsyslogd-pstats: main Q: size=9969 enqueued=1051065 full=32499 maxqsize=10000
2017-04-28T21:58:31.805134-04:00 vlrtp401 rsyslogd-pstats: imuxsock: submitted=134 ratelimit.discarded=0 ratelimit.numratelimiters=96
2017-04-28T21:58:31.946635-04:00 vlrtp401 rsyslogd-pstats: main Q: size=9969 enqueued=1182457 full=36605 maxqsize=10000
2017-04-28T22:03:32.046137-04:00 vlrtp401 rsyslogd-pstats: imuxsock: submitted=154 ratelimit.discarded=0 ratelimit.numratelimiters=112
2017-04-28T22:03:32.168724-04:00 vlrtp401 rsyslogd-pstats: main Q: size=9969 enqueued=1313849 full=40711 maxqsize=10000
2017-04-28T22:08:32.268147-04:00 vlrtp401 rsyslogd-pstats: imuxsock: submitted=189 ratelimit.discarded=0 ratelimit.numratelimiters=134
2017-04-28T22:08:32.373070-04:00 vlrtp401 rsyslogd-pstats: main Q: size=9969 enqueued=1444697 full=44800 maxqsize=10000
2017-04-28T22:13:32.472131-04:00 vlrtp401 rsyslogd-pstats: imuxsock: submitted=211 ratelimit.discarded=0 ratelimit.numratelimiters=152
2017-04-28T22:13:32.578257-04:00 vlrtp401 rsyslogd-pstats: main Q: size=9969 enqueued=1574745 full=48864 maxqsize=10000
a212830
Avarage
 
Posts: 12
Joined: Wed Jan 09, 2013 11:54 pm

Re: How can i can determine if rsyslog is dropping msgs?

Postby dlang » Sat Apr 29, 2017 4:19 am

the fact that your last data says full=48864 says that the queues were full almost 50k times.

unfortunately with such an ancient version, impstats doesn't give a lot of other information about what's going on.

my first suspicion would be that you are writing to too many files in your dynafile output. have you set the dynafilecachesize appropriately?
dlang
Frequent Poster
 
Posts: 1001
Joined: Mon Sep 15, 2008 7:44 am

Re: How can i can determine if rsyslog is dropping msgs?

Postby a212830 » Sat Apr 29, 2017 1:22 pm

I updated my dynacachefilesize to 500. I usually only have about 175 files open at one time, but wanted to be safe.

Here's the latest output from impstats. The counters appear to be accumulating, and I don't see any way to prevent that from happening.

2017-04-29T07:58:00.530865-04:00 vlrtp401 rsyslogd-pstats: imuxsock: submitted=32 ratelimit.discarded=0 ratelimit.numratelimiters=29
2017-04-29T07:58:00.614877-04:00 vlrtp401 rsyslogd-pstats: main Q: size=9969 enqueued=402550 full=12235 maxqsize=10000
2017-04-29T08:03:00.702863-04:00 vlrtp401 rsyslogd-pstats: imuxsock: submitted=53 ratelimit.discarded=0 ratelimit.numratelimiters=46
2017-04-29T08:03:00.818376-04:00 vlrtp401 rsyslogd-pstats: main Q: size=9969 enqueued=534454 full=16357 maxqsize=10000
2017-04-29T08:08:00.911244-04:00 vlrtp401 rsyslogd-pstats: imuxsock: submitted=61 ratelimit.discarded=0 ratelimit.numratelimiters=54
2017-04-29T08:08:01.013849-04:00 vlrtp401 rsyslogd-pstats: main Q: size=9969 enqueued=665302 full=20446 maxqsize=10000
2017-04-29T08:13:01.110966-04:00 vlrtp401 rsyslogd-pstats: imuxsock: submitted=89 ratelimit.discarded=0 ratelimit.numratelimiters=75
2017-04-29T08:13:01.305041-04:00 vlrtp401 rsyslogd-pstats: main Q: size=9969 enqueued=793942 full=24466 maxqsize=10000
2017-04-29T08:18:01.404140-04:00 vlrtp401 rsyslogd-pstats: imuxsock: submitted=119 ratelimit.discarded=0 ratelimit.numratelimiters=91
2017-04-29T08:18:01.513463-04:00 vlrtp401 rsyslogd-pstats: main Q: size=9969 enqueued=923254 full=28507 maxqsize=10000
a212830
Avarage
 
Posts: 12
Joined: Wed Jan 09, 2013 11:54 pm

Re: How can i can determine if rsyslog is dropping msgs?

Postby dlang » Sat Apr 29, 2017 6:39 pm

unfortunantly without more detailed output from impstats (which isn't available in that ancient a version), tracking this down is hard.

you can try looking at the usage of each thread ('H' in top breaks things down by thread), you probably will find one thread that is using 100% cpu

setting your batchsize larger may help.

you can do a strace of the maxed out thread and see what sort of system calls it's making.

look at your disk I/O stats (iostat) and make sure that you aren't maxing out your storage capacity

but you really do need to get that box on a newer version
dlang
Frequent Poster
 
Posts: 1001
Joined: Mon Sep 15, 2008 7:44 am

Re: How can i can determine if rsyslog is dropping msgs?

Postby a212830 » Sat Apr 29, 2017 7:50 pm

How would I set the batch size on this version?
a212830
Avarage
 
Posts: 12
Joined: Wed Jan 09, 2013 11:54 pm

Re: How can i can determine if rsyslog is dropping msgs?

Postby a212830 » Tue May 02, 2017 11:57 am

Anyone?
a212830
Avarage
 
Posts: 12
Joined: Wed Jan 09, 2013 11:54 pm

Re: How can i can determine if rsyslog is dropping msgs?

Postby Intelligent_Silicon » Fri May 26, 2017 6:12 pm

If you have a device like a router where you can direct the syslog output to the rsyslog machine, some devices will send their boot up msgs to the syslog server, this way you can see if the msgs are being received, processed and written in order, or if any are being lost over the network due to poor cabling. If you need to scale up, maybe get multiple devices and switch them all on at the same time using some sort of programmable power supply.

Another option is to write your own app which can send out sequentially numbered syslog messages to the rsyslog machine to makes sure they are received in order.

Having a managed switch where you can mirror a ports tcp/ip traffic to a log will also help you verify that the syslog messages are being sent to the rsyslog machine unless the data is encrypted (unlikely in this case). Wireshark/tshark can be useful for monitoring the tcp/ip traffic received by the rsyslog machine, so having established that data was sent from the switch, then it becomes a case of tracing the data through the rsyslog machine, so you could configure iptables (if using Linux) to veryify the tcp/ip data was received by the rsyslog machine and then switch on debug in rsyslog to make sure the syslog messages are being received and then follow the syslog messages through the rsyslog debug trace file.

Maybe you are seeing the same thing mentioned in this thread? Maybe using the rsyslog.conf from the thread below may help you determine whats going on?
syslog-msgs-not-being-written-disk-realtime-t13022.html

Its a security risk if you cant spot anomalies in your log files, so I understand your concern.
Intelligent_Silicon
New
 
Posts: 2
Joined: Fri May 26, 2017 4:53 pm

Google Ads



Return to General

Who is online

Users browsing this forum: No registered users and 2 guests

cron