There are a couple of those: LinuxIPTablesFile: origin=omfile requests=138877957 level0=19864683 missed=91303303 evicted=91292586 maxused=10 closetimeouts=0
have a look at the evicted count! This totally kills performance. Each time one entry needs to be evicted, the file is closed, and a new one is opened. You should set the cache size for this action to match roughly the number of files that you want to keep open during normal operations (e.g. if you have 1000 hosts and include hour and hostname in the dynafile name, the cache size should be around 1000, except if you have some low talkers. Also note the online tool at http://www.rsyslog.com/impstats-analyzer/ It probably will spit out a couple of warnings if you submit the pstats. HTH Rainer 2015-10-06 15:29 GMT+02:00 Woodruff, Dan <[email protected]>: > Rainer, thank you. Here is a full extract of a recent impstats run: > > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: imuxsock: origin=imuxsock > submitted=282984 ratelimit.discarded=0 ratelimit.numratelimiters=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache StatsFile: > origin=omfile requests=326648 level0=325603 missed=1045 evicted=0 maxused=1 > closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 1: origin=core.action > processed=326648 failed=0 suspended=0 suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 2: origin=core.action > processed=3255090916 failed=0 suspended=2 suspended.duration=240 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache LDAPFile: > origin=omfile requests=3171530030 level0=3171529033 missed=997 evicted=0 > maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 3: origin=core.action > processed=3171530030 failed=0 suspended=0 suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > LinuxIPTablesFile: origin=omfile requests=138877957 level0=19864683 > missed=91303303 evicted=91292586 maxused=10 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 4: origin=core.action > processed=138877957 failed=0 suspended=0 suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache LinuxUFWFile: > origin=omfile requests=0 level0=0 missed=0 evicted=0 maxused=0 > closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 5: origin=core.action > processed=0 failed=0 suspended=0 suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache DHCPFile: > origin=omfile requests=3518037 level0=3516992 missed=1045 evicted=0 > maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 6: origin=core.action > processed=3518037 failed=0 suspended=0 suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > LinuxBlankProgramFile: origin=omfile requests=93283 level0=28347 missed=1932 > evicted=15 maxused=10 closetimeouts=303 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 7: origin=core.action > processed=93283 failed=0 suspended=0 suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > LinuxProgramFile: origin=omfile requests=358821719 level0=245218530 > missed=23914416 evicted=23903728 maxused=10 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 8: origin=core.action > processed=358821719 failed=0 suspended=0 suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > 10514Catchall: origin=omfile requests=0 level0=0 missed=0 evicted=0 > maxused=0 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 9: origin=core.action > processed=0 failed=0 suspended=0 suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > WindowsSecFile: origin=omfile requests=232842816 level0=189594825 > missed=19555094 evicted=19544459 maxused=10 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 10: > origin=core.action processed=232842816 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > WindowsSecFile: origin=omfile requests=18059 level0=17740 missed=319 > evicted=0 maxused=1 closetimeouts=68 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 11: > origin=core.action processed=18059 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > WindowsAppFile: origin=omfile requests=14111964 level0=8603913 > missed=4387715 evicted=4377380 maxused=10 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 12: > origin=core.action processed=14111964 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > WindowsSysFile: origin=omfile requests=7726972 level0=4070882 missed=3120334 > evicted=3110190 maxused=10 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 13: > origin=core.action processed=7726972 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > ParkingPayStationFile: origin=omfile requests=0 level0=0 missed=0 evicted=0 > maxused=0 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 14: > origin=core.action processed=0 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > WindowsProgramFileNoDotLog: origin=omfile requests=238047839 > level0=217994829 missed=17165101 evicted=17154494 maxused=10 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 15: > origin=core.action processed=238047839 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > WindowsProgramFile: origin=omfile requests=4203850 level0=3349630 > missed=64805 evicted=57326 maxused=10 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 16: > origin=core.action processed=4203850 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 17: > origin=core.action processed=33461 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > EduroamACSFile: origin=omfile requests=33461 level0=33090 missed=371 > evicted=0 maxused=1 closetimeouts=56 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: writeEduroamACSFile: > origin=core.action processed=33461 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > ProofpointMailFile: origin=omfile requests=2431224 level0=2430182 > missed=1042 evicted=0 maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 19: > origin=core.action processed=2431224 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > ProofpointMailFile: origin=omfile requests=8392912 level0=8391872 > missed=1040 evicted=0 maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 20: > origin=core.action processed=8392912 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > ProofpointMailFile: origin=omfile requests=329014078 level0=329013005 > missed=1073 evicted=0 maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 21: > origin=core.action processed=329014078 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 22: > origin=core.action processed=0 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > EduroamACSFile: origin=omfile requests=0 level0=0 missed=0 evicted=0 > maxused=0 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: writeEduroamACSFile: > origin=core.action processed=0 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > InternetFirewallFile: origin=omfile requests=828180536 level0=828180031 > missed=505 evicted=0 maxused=1 closetimeouts=4 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 24: > origin=core.action processed=828180536 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > DatacenterFirewallsFile: origin=omfile requests=4671839581 level0=4671839032 > missed=549 evicted=0 maxused=1 closetimeouts=1 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 25: > origin=core.action processed=4671839581 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > GuestFirewallFile: origin=omfile requests=1092941069 level0=1092939995 > missed=1074 evicted=0 maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 26: > origin=core.action processed=1092941069 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 27: > origin=core.action processed=11161 failed=0 suspended=5 > suspended.duration=18180 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 28: > origin=core.action processed=1410808842 failed=0 suspended=1 > suspended.duration=120 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache PAUPNSFile: > origin=omfile requests=1410808842 level0=1410807768 missed=1074 evicted=0 > maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 29: > origin=core.action processed=1410808842 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > InternetFirewallFile: origin=omfile requests=4983337256 level0=4983336182 > missed=1074 evicted=0 maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 30: > origin=core.action processed=4983337256 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > DatacenterFirewallsFile: origin=omfile requests=2192714197 level0=2192713123 > missed=1074 evicted=0 maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 31: > origin=core.action processed=2192714197 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache VPNFile: > origin=omfile requests=38225317 level0=38224245 missed=1072 evicted=0 > maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 32: > origin=core.action processed=38225317 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > OtherFirewallsFile: origin=omfile requests=749942007 level0=749940933 > missed=1074 evicted=0 maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 33: > origin=core.action processed=749942007 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > F5TrafficFile: origin=omfile requests=0 level0=0 missed=0 evicted=0 > maxused=0 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 34: > origin=core.action processed=0 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache F5SystemFile: > origin=omfile requests=731213 level0=730312 missed=901 evicted=0 maxused=1 > closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 35: > origin=core.action processed=731213 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache UCSFile: > origin=omfile requests=750887 level0=750365 missed=522 evicted=0 maxused=1 > closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 36: > origin=core.action processed=750887 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > WirelessMSEFile: origin=omfile requests=6949336 level0=6948288 missed=1048 > evicted=0 maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 37: > origin=core.action processed=6949336 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > RouterSwitchFile: origin=omfile requests=3769868 level0=3768811 missed=1057 > evicted=0 maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 38: > origin=core.action processed=3769868 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache WirelessFile: > origin=omfile requests=1487262 level0=1486249 missed=1013 evicted=0 > maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 39: > origin=core.action processed=1487262 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > WirelessSNMPTrapFile: origin=omfile requests=26125252 level0=26124183 > missed=1069 evicted=0 maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 40: > origin=core.action processed=26125252 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 41: > origin=core.action processed=9983 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > InfoBloxDNSFile: origin=omfile requests=26715671 level0=26714601 missed=1070 > evicted=0 maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 42: > origin=core.action processed=26715671 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > GuestDHCPFile: origin=omfile requests=2826618 level0=2825621 missed=997 > evicted=0 maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 43: > origin=core.action processed=2826618 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache DHCPFile: > origin=omfile requests=36071731 level0=36070662 missed=1069 evicted=0 > maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 44: > origin=core.action processed=36071731 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > InfoBloxTFTPFile: origin=omfile requests=40511 level0=39971 missed=540 > evicted=0 maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 45: > origin=core.action processed=40511 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > InfoBloxFTPFile: origin=omfile requests=259345 level0=258636 missed=709 > evicted=0 maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 46: > origin=core.action processed=259345 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > InfoBloxSystemFile: origin=omfile requests=3591 level0=3414 missed=177 > evicted=0 maxused=1 closetimeouts=123 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 47: > origin=core.action processed=3591 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache WirelessFile: > origin=omfile requests=0 level0=0 missed=0 evicted=0 maxused=0 > closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 48: > origin=core.action processed=0 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache IPSNSCFile: > origin=omfile requests=578 level0=17 missed=561 evicted=0 maxused=1 > closetimeouts=384 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 49: > origin=core.action processed=578 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > PAPanoramaFile: origin=omfile requests=1626 level0=1353 missed=273 evicted=0 > maxused=1 closetimeouts=216 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 50: > origin=core.action processed=1626 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache VMwareFile: > origin=omfile requests=24671909 level0=21711636 missed=8569 evicted=0 > maxused=10 closetimeouts=2 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 51: > origin=core.action processed=24671909 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > NimbleStorageFile: origin=omfile requests=1872 level0=1519 missed=353 > evicted=0 maxused=1 closetimeouts=26 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 52: > origin=core.action processed=1872 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache TandbergFile: > origin=omfile requests=3157330 level0=3156354 missed=976 evicted=0 maxused=1 > closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 53: > origin=core.action processed=3157330 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > WirelessACSFile: origin=omfile requests=20179879 level0=20178820 missed=1059 > evicted=0 maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 54: > origin=core.action processed=20179879 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > CiscoTACACSFile: origin=omfile requests=2033215 level0=2032189 missed=1026 > evicted=0 maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 55: > origin=core.action processed=2033215 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache > WifiVoiceFile: origin=omfile requests=31791968 level0=31790912 missed=1056 > evicted=0 maxused=1 closetimeouts=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 56: > origin=core.action processed=31791968 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: dynafile cache 514Catchall: > origin=omfile requests=2289029 level0=1686733 missed=73481 evicted=67905 > maxused=10 closetimeouts=3 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 57: > origin=core.action processed=2289029 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 58: > origin=core.action processed=0 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 59: > origin=core.action processed=0 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 60: > origin=core.action processed=0 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 61: > origin=core.action processed=0 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 62: > origin=core.action processed=0 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 63: > origin=core.action processed=0 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 64: > origin=core.action processed=1483 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 65: > origin=core.action processed=1791065 failed=0 suspended=1 > suspended.duration=30 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 66: > origin=core.action processed=354060 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 67: > origin=core.action processed=169981 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 68: > origin=core.action processed=108683 failed=0 suspended=0 > suspended.duration=0 resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 69: > origin=core.action processed=177 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 70: > origin=core.action processed=2293 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 71: > origin=core.action processed=0 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 72: > origin=core.action processed=0 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: action 73: > origin=core.action processed=0 failed=0 suspended=0 suspended.duration=0 > resumed=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: imudp(*:10514): origin=imudp > submitted=479685225 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: imudp(*:10514): origin=imudp > submitted=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: imudp(*:10515): origin=imudp > submitted=5975133 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: imudp(*:10515): origin=imudp > submitted=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: imudp(*:10516): origin=imudp > submitted=339871633 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: imudp(*:10516): origin=imudp > submitted=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: imudp(*:514): origin=imudp > submitted=16144045540 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: imudp(*:514): origin=imudp > submitted=0 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: imtcp(10514): origin=imtcp > submitted=3193156385 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: imtcp(10515): origin=imtcp > submitted=718953659 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: imtcp(10516): origin=imtcp > submitted=42 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: imtcp(514): origin=imtcp > submitted=13811943 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: resource-usage: > origin=impstats utime=258463851109 stime=106179564820 maxrss=628664 > minflt=64198329 majflt=328 inblock=3994087 oublock=1185161320 > nvcsw=-30119740 nivcsw=28845012 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: LinuxRuleSet: > origin=core.queue size=0 enqueued=3672841610 full=0 discarded.full=0 > discarded.nf=0 maxqsize=350911 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: WindowsRuleSet: > origin=core.queue size=0 enqueued=724928792 full=0 discarded.full=0 > discarded.nf=0 maxqsize=156862 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: MailRuleSet: > origin=core.queue size=0 enqueued=339871675 full=0 discarded.full=0 > discarded.nf=0 maxqsize=5169 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: NetworkDeviceRuleSet: > origin=core.queue size=0 enqueued=16157857483 full=0 discarded.full=0 > discarded.nf=0 maxqsize=456471 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: main Q: origin=core.queue > size=109 enqueued=1793778 full=0 discarded.full=0 discarded.nf=0 > maxqsize=1738 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: imudp(w1): origin=imudp > called.recvmmsg=10746838213 called.recvmsg=0 msgs.received=4701905926 > Oct 6 08:27:07 its-syslog-up1 rsyslogd-pstats: imudp(w0): origin=imudp > called.recvmmsg=17603520106 called.recvmsg=0 msgs.received=12267671605 > > -----Original Message----- > From: [email protected] > [mailto:[email protected]] On Behalf Of Rainer Gerhards > Sent: Tuesday, October 6, 2015 9:06 AM > To: rsyslog-users <[email protected]> > Subject: Re: [rsyslog] RHEL7.1 / rsyslog 8.x random message loss > > 2015-10-06 14:57 GMT+02:00 Woodruff, Dan <[email protected]>: >> Thank you David. From what I see, none of the queues are getting full. >> >> None of the actions - I have 73 total - have a 'failed' count of >> greater than zero. Four have a 'suspended' count in the single digits. >> >> When you said "if you are writing to a local file, you should not need >> to have a separate queue", does queue equate to ruleset in this case? >> The main reason I have the separate rulesets is to handle different >> kinds of incoming logs on different ports, making it easier to write >> the rules logic for the different types. Does that make sense? >> >> There is a high number of dynafiles, specifically for server logs, >> which we break out into files by host and programname with these > templates: >> template(name="LinuxProgramFile" type="string" >> string="/var/log/collection/linux/%fromhost:::lowercase%/%programname% >> .log") template(name="WindowsProgramFile" type="string" >> string="/var/log/collection/windows/%HOSTNAME:::lowercase%/%programnam >> e%.log >> ") >> >> The result is about 32,000 total dynafiles which are then rotated out > daily. >> >> Looking at top, rsyslogd as a whole never goes above 120%. Most of the >> threads hang out below 15% with the busiest one - rs:NetworkDevic - >> hitting about 50% during peak. Although I hadn't noticed this before, >> watching top for a few minutes this morning, rsyslogd hangs out around >> 60%, then bursts to almost 200% for one second, then disappears from >> top in the next second, before returning to 60%. It cycled through this > every 10 seconds or so. >> After restarting rsyslogd, the behavior went away - it's staying around > 60%. > > This could be caused by a too-small dynafile cache. I haven't located the > conf for these actions with 32,000 files nor the stats, but depending on > size it could be the problem. Please post the *full* impstats log. > > Rainer >> >> Should I try lowering the number of threads for the rulesets/imudp? >> This issue does happen with both TCP and UDP, however, which further >> compounds my confusion. You mention systemd - I'll look into that as I >> have a case open with RH. >> >> Dan >> >> >> -----Original Message----- >> From: [email protected] >> [mailto:[email protected]] On Behalf Of David Lang >> Sent: Monday, October 5, 2015 3:23 PM >> To: rsyslog-users <[email protected]> >> Subject: Re: [rsyslog] RHEL7.1 / rsyslog 8.x random message loss >> >> doing a cut-n-past since this client doesn't quote signed messages > properly: >> >> >> David, thank you. Apologies, I had cut out the dynafile for testing. >> Here is some additional config file: >> >> template(name="EduroamACSFile" type="string" >> string="/var/log/collection/eduroam_acs.log") >> template(name="EduroamACSFormat" type="string" string="%timestamp% >> %hostname% %syslogtag%%msg:::escape-cc%\n") >> >> ruleset(name="ruleset1" queue.type="LinkedList" queue.size="750000" >> queue.workerthreads="4") { >> # at very top of ruleset - IPs obscured for privacy >> if $fromhost-ip == 'x.x.2.75' >> or $fromhost-ip == 'x.x.2.85' >> then { >> /tmp/debug.log;RSYSLOG_DebugFormat >> action(type="omfile" dynaFile="EduroamACSFile" >> template="EduroamACSFormat" name="writeEduroamACSFile") >> stop >> } >> #... other rules below >> } # end ruleset >> >> I do have impstats enabled for every 5 minutes. Here's output specific >> to this file for a recent sample for this file, plus the general rule >> set >> queues: >> >> Oct 5 14:06:47 its-syslog-up1 rsyslogd-pstats: dynafile cache >> EduroamACSFile: origin=omfile requests=31123 level0=30781 missed=342 >> evicted=0 maxused=1 closetimeouts=51 >> Oct 5 14:06:47 its-syslog-up1 rsyslogd-pstats: writeEduroamACSFile: >> origin=core.action processed=31123 failed=0 suspended=0 >> suspended.duration=0 >> resumed=0 >> >> Oct 5 14:11:47 its-syslog-up1 rsyslogd-pstats: resource-usage: >> origin=impstats utime=217851481196 stime=87433080781 maxrss=628664 >> minflt=43999703 majflt=216 inblock=3033769 oublock=-1119976592 >> nvcsw=379912551 nivcsw=20999555 >> Oct 5 14:11:47 its-syslog-up1 rsyslogd-pstats: LinuxRuleSet: >> origin=core.queue size=6 enqueued=3304935974 full=0 discarded.full=0 >> discarded.nf=0 maxqsize=350911 >> Oct 5 14:11:47 its-syslog-up1 rsyslogd-pstats: WindowsRuleSet: >> origin=core.queue size=0 enqueued=648043087 full=0 discarded.full=0 >> discarded.nf=0 maxqsize=156862 >> Oct 5 14:11:47 its-syslog-up1 rsyslogd-pstats: MailRuleSet: >> origin=core.queue size=0 enqueued=307960420 full=0 discarded.full=0 >> discarded.nf=0 maxqsize=4243 >> Oct 5 14:11:47 its-syslog-up1 rsyslogd-pstats: NetworkDeviceRuleSet: >> origin=core.queue size=0 enqueued=11008320810 full=0 discarded.full=0 >> discarded.nf=0 maxqsize=456471 >> Oct 5 14:11:47 its-syslog-up1 rsyslogd-pstats: main Q: >> origin=core.queue >> size=120 enqueued=1496835 full=0 discarded.full=0 discarded.nf=0 >> maxqsize=1738 >> Oct 5 14:11:47 its-syslog-up1 rsyslogd-pstats: imudp(w1): >> origin=imudp >> called.recvmmsg=8282193695 called.recvmsg=0 msgs.received=2833007396 >> Oct 5 >> 14:11:47 its-syslog-up1 rsyslogd-pstats: imudp(w0): origin=imudp >> called.recvmmsg=14154695256 called.recvmsg=0 msgs.received=8909255564 >> >> To estimate volume of logs this is receiving, I took a recent impstats >> output for enqueued for all rule sets and added them, then subtracted >> the values from an hour ago, divided by 3600 to get msgs/second and got > 29521. >> This is peak time of day for us so I would expect this to be the high >> point, dropping to less than half that in the middle of the night. >> Messages are still randomly lost in the middle of the night. If >> there's a better way to estimate volume being processed by the machine, > let me know! >> >> >> >> >> >> >> look at the inputs, impudp shows the number of messages received >> >> then you look at the various queues (if everything is in a separate >> queue, that also leads to a bottleneck), are any of them getting full at > peak load? >> >> Then you look at the various actions, are any of them showing errors? >> >> the number of messages enqueued for all items (or even all queues) may >> be substantially larger or smaller (depending on if a message is >> handled by multiple rules or is filtered out and never processed) >> >> so your 29K logs/sec is probably a fairly inflated value, but even >> that should be just fine with a single worker. >> >> if you are writing to a local file, you should not need to have a >> separate queue (compression could change things, only move things to a >> separate queue if testing shows that you run out of CPU otherwise, or >> if that output could >> block) >> >> >> in your dynafile actions, how many different files is it producing? >> >> for example: >> action(type="omfile" dynaFile="EduroamACSFile" template="EduroamACSFormat" >> name="writeEduroamACSFile") >> is hard coded to a single file in the example provided, and would be >> slightly faster just writing to that file. >> >> also, run top, enable per-thread reporting (press 'H') and see if any >> of the rsyslog threads are using 100% cpu. >> >> RHEL/CentOS7 do introduce systemd, and systemd may be doing something >> to prevent rsyslog from 'hogging' the cpu, but I don't know what it's >> defaults are. >> >> David Lang >> >> _______________________________________________ >> rsyslog mailing list >> https://urldefense.proofpoint.com/v2/url?u=http-3A__lists.adiscon.net_ >> mailman_listinfo_rsyslog&d=BQICAg&c=kbmfwr1Yojg42sGEpaQh5ofMHBeTl9EI2e >> aqQZhHbOU&r=0S5vJ8-FmQy6Qk5D6_T4U9EYbkCcMc4ijDuyUem89Lk&m=9W72LK2cU4WU >> GyGzkIF2InK857eOyaFb6j0YdVFx4qA&s=2-ppyLafd356a2uXJMOqKvl0O10_0nQ5wsIq >> VZclCjo&e= >> https://urldefense.proofpoint.com/v2/url?u=http-3A__www.rsyslog.com_pr >> ofessional-2Dservices_&d=BQICAg&c=kbmfwr1Yojg42sGEpaQh5ofMHBeTl9EI2eaq >> QZhHbOU&r=0S5vJ8-FmQy6Qk5D6_T4U9EYbkCcMc4ijDuyUem89Lk&m=9W72LK2cU4WUGy >> GzkIF2InK857eOyaFb6j0YdVFx4qA&s=cTVShGFUSRv25R8o7f-BI61qtyxr9YNAb2KMZ5 >> rCYdI&e= What's up with rsyslog? Follow >> https://urldefense.proofpoint.com/v2/url?u=https-3A__twitter.com_rgerh >> ards&d=BQICAg&c=kbmfwr1Yojg42sGEpaQh5ofMHBeTl9EI2eaqQZhHbOU&r=0S5vJ8-F >> mQy6Qk5D6_T4U9EYbkCcMc4ijDuyUem89Lk&m=9W72LK2cU4WUGyGzkIF2InK857eOyaFb >> 6j0YdVFx4qA&s=WUitGA64trP-JmgCrDBuFUS9J-4SexXtH4RLf2x4A1w&e= >> NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad > of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T > LIKE THAT. > _______________________________________________ > rsyslog mailing list > https://urldefense.proofpoint.com/v2/url?u=http-3A__lists.adiscon.net_mailma > n_listinfo_rsyslog&d=BQICAg&c=kbmfwr1Yojg42sGEpaQh5ofMHBeTl9EI2eaqQZhHbOU&r= > 0S5vJ8-FmQy6Qk5D6_T4U9EYbkCcMc4ijDuyUem89Lk&m=9W72LK2cU4WUGyGzkIF2InK857eOya > Fb6j0YdVFx4qA&s=2-ppyLafd356a2uXJMOqKvl0O10_0nQ5wsIqVZclCjo&e= > https://urldefense.proofpoint.com/v2/url?u=http-3A__www.rsyslog.com_professi > onal-2Dservices_&d=BQICAg&c=kbmfwr1Yojg42sGEpaQh5ofMHBeTl9EI2eaqQZhHbOU&r=0S > 5vJ8-FmQy6Qk5D6_T4U9EYbkCcMc4ijDuyUem89Lk&m=9W72LK2cU4WUGyGzkIF2InK857eOyaFb > 6j0YdVFx4qA&s=cTVShGFUSRv25R8o7f-BI61qtyxr9YNAb2KMZ5rCYdI&e= > What's up with rsyslog? Follow > https://urldefense.proofpoint.com/v2/url?u=https-3A__twitter.com_rgerhards&d > =BQICAg&c=kbmfwr1Yojg42sGEpaQh5ofMHBeTl9EI2eaqQZhHbOU&r=0S5vJ8-FmQy6Qk5D6_T4 > U9EYbkCcMc4ijDuyUem89Lk&m=9W72LK2cU4WUGyGzkIF2InK857eOyaFb6j0YdVFx4qA&s=WUit > GA64trP-JmgCrDBuFUS9J-4SexXtH4RLf2x4A1w&e= > NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of > sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T > LIKE THAT. > > _______________________________________________ > rsyslog mailing list > http://lists.adiscon.net/mailman/listinfo/rsyslog > http://www.rsyslog.com/professional-services/ > What's up with rsyslog? Follow https://twitter.com/rgerhards > NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of > sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T > LIKE THAT. _______________________________________________ rsyslog mailing list http://lists.adiscon.net/mailman/listinfo/rsyslog http://www.rsyslog.com/professional-services/ What's up with rsyslog? Follow https://twitter.com/rgerhards NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE THAT.
