Discussion for KB Entry 6921 - Syslogtag rsyslog-2163

Discussions around Windows Eventlog messages.

Moderator: rgerhards

Google Ads


Discussion for KB Entry 6921 - Syslogtag rsyslog-2163

Postby knowledgebase » Tue Mar 29, 2011 12:19 pm

This is the discussion thread for the Knowledge Base Entry 6921

Vendor: Adiscon
Software/Device: rsyslog
Syslogtag: rsyslog-2163
Link to KB Entry

Short Description:
epoll_ctl API fails
knowledgebase
Forum Bot
 
Posts: 170
Joined: Wed May 28, 2008 10:09 am

Re: Discussion for KB Entry 6921 - Syslogtag rsyslog-2163

Postby deltadelta » Thu Oct 17, 2013 12:18 pm

Hi,

I recently upgraded to v5.10.1 of rsyslog and got the following error messages after around 2 weeks of runtime:
Code: Select all
rsyslogd-2163: [err]epoll_ctl failed on fd 21, id 0/0x2af8978a8be0, op 1 with File exists


The next message logged suggested this KB article. As the KB says a fix was put in after 5.7.10 and to post if it's seen in any other circumstances, I thought I'd let you know. I appreciate this isn't the exact error message, so if this shouldn't be here, feel free to remove this post or move it elsewhere.

This error message was posted numerous times along with:
Code: Select all
rsyslogd-2163: [err] last message repeated 27612 times


The number of times a message was repeated varied. This went on for around an hour, before the message appeared hundreds of times per second. Eventually I saw a lot of issues surrounding no memory left and various other services (including rsyslog) trying to free memory up, invoking oom-killer. Various services were killed. Then the original messages started again, followed by the oom-killer being invoked again.

The only was I could get the box up and running again, was to restart rsyslog. This (fortunately) was on out test systems and we are in the process of updating the latest and greatest version.
deltadelta
New
 
Posts: 3
Joined: Thu Sep 26, 2013 1:03 pm

Re: Discussion for KB Entry 6921 - Syslogtag rsyslog-2163

Postby darren.h » Thu Jan 16, 2014 4:30 am

Saw this problem today with rsyslogd 5.8.10, installed on Linux 3.4.66-55.43.amzn1.x86_64

Filled up the entire syslog disk with the error message.

Jan 15 21:37:49 hostname rsyslogd-2163: epoll_ctl failed on fd 36, id 0/0x7f275c00de40, op 1 with File exists
: File exists [try http://www.rsyslog.com/e/2163 ]
darren.h
New
 
Posts: 1
Joined: Thu Jan 16, 2014 4:26 am

Re: Discussion for KB Entry 6921 - Syslogtag rsyslog-2163

Postby JohnE » Wed Jul 16, 2014 9:23 pm

I also have recently been having this issue. I don't know why it's occuring. It has occured 2x in the last week. The first time /var got full, which was obvious after the reboot. Today /var/was getting full (/var/log/messages was 123GB, but /var is +400 GB), but I guess the memory ran out first. Either way, the box would not respond nor let us in, and we have to reboot.

The issue begins to fill the disk with gazillions of these messages in /var/log/messages:
Jul 15 23:10:09 myhost rsyslogd-2163: epoll_ctl failed on fd 84, id 0/0x2ba3d00e5fc0, op 1 with File exists
: File exists [try http://www.rsyslog.com/e/2163 ]

Admittedly i have $RepeatedMsgReduction off
NOTE: I don't want to argue this point, which is ancillary anyway, and only accounts for a full disk...not the root cause of the issue.
This is a audit logging system where I am required to track each log message and cannot allow the "this message repeated" feature to function.



Before the events begin in /var/log/messges, it looks normal....dhcp client renewals, xinitd messgaes, etc
...no errors or indications of pending doom whatssoever.

Any assitance is appreciated!
Thanks!


Here's a quick overview of the system:
=================================
# rpm -qa|grep syslog
rsyslog5-5.8.12-4.el5
#
# uname -a
Linux myhost 2.6.18-348.1.1.el5 #1 SMP Fri Dec 14 05:25:59 EST 2012 x86_64 x86_64 x86_64 GNU/Linux
#
# ps -ef|grep syslog
root 21107 1 0 18:44 ? 00:00:01 vxconfigd -x syslog
root 21909 1 8 18:45 ? 00:05:38 /sbin/rsyslogd -i /var/run/rsyslogd.pid -c 5
root 31942 26354 0 19:52 pts/1 00:00:00 grep syslog
#


Rsyslog Configuration
===================================
# 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

# Provides TCP syslog reception
$ModLoad imtcp
$InputTCPServerRun 39000


#### GLOBAL DIRECTIVES ####

# Use default timestamp format
$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat
$template myFileformat, "%timegenerated% %hostname% %syslogtag%%msg%\n"
$template myFilename, "/var/log/myapp/mylogs-%$YEAR%%$MONTH%%$DAY%_%$HOUR%.log"


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


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


#### RULES ####

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

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

# The authpriv file has restricted access.
authpriv.*;auth.* /var/log/secure
authpriv.*;auth.* @thatloghostt.mydomain.com


# 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

#MY App specific rules
local0.emerg ~
local0.alert ~
local0.crit ~
local0.err ~
local0.warn ~
local0.notice ~
local0.info ~
local0.debug ?myFilename;myFileformat
JohnE
New
 
Posts: 3
Joined: Wed Jul 16, 2014 8:30 pm

Re: Discussion for KB Entry 6921 - Syslogtag rsyslog-2163

Postby rgerhards » Thu Jul 17, 2014 11:14 am

Which version of rsyslog is that? The current one (8.2.3, I think, at the time of this writing) should not have that issue any longer.
rgerhards
Site Admin
 
Posts: 3807
Joined: Thu Feb 13, 2003 11:57 am

Re: Discussion for KB Entry 6921 - Syslogtag rsyslog-2163

Postby JohnE » Fri Jul 18, 2014 4:05 am

The server in question is running:
rpm -qa|grep syslog
rsyslog5-5.8.12-4.el5
uname -a
Linux myhost 2.6.18-348.1.1.el5 #1 SMP Fri Dec 14 05:25:59 EST 2012 x86_64 x86_64 x86_64 GNU/Linux
cat /etc/redhat-release
Red Hat Enterprise Linux Server release 5.9 (Tikanga)

We have recently converted to rsyslog (from sysklogd) on our application servers that run RHEL5 and RHEL6. Since rsyslog v5 was the default version on RHEL6, we chose rsyslog v5 as well for the RHEL5 servers, upgrading from sysklogd on those. We choose to match rsyslog versions at v5 on the outlying servers for reasons of consistency of support for our teams, and v5 seemed to have all the features we needed.

On average the message rate at the central logger is ~350/sec. We have not seen this issue on the outlying servers, which individually have a much smaller rsyslog message send rate.

We did not see this problem in lab testing prior to prod rollout, but did run millions of syslogs thru a smaller lab networked system with TCP forwarding and queing enabled, per the config posted previously.

After this problem occurred, per advice on the Red Hat support site at this link (https://bugzilla.redhat.com/show_bug.cgi?id=848852) to increase the ulimit and effectively raise the open file limit, and with the understanding that the default for this is 1024, I have added the rsyslog parameter to our config:
$MaxOpenFiles = 2048
There was no error upon rsyslog restart, so it appears that setting was accepted and is working ok. However, I have not modified /etc/security/limits.conf at this time.

Thoughts?
JohnE
New
 
Posts: 3
Joined: Wed Jul 16, 2014 8:30 pm

Re: Discussion for KB Entry 6921 - Syslogtag rsyslog-2163

Postby barryh » Tue Aug 05, 2014 12:09 pm

We have recently had the error epoll_ctl on our rsyslog server.

The issue being this happened after the reported fix was applied 5.7.10
All of the relevant details have been included below.

If there are any more details that you would like I can provide them.
Our Rsyslog package is the default version supplied by RedHat as the RPM
At this point in time this hasn't been raised with RedHat.
(I have had to modify the URL in the error message to fit in with the forum rules)

2014-08-04T12:37:45.064743+10:00 <Server> rsyslogd-2163: epoll_ctl failed on fd 344, id 0/0x7ffbe4094090, op 1 with File exists: File exists [try http ://www .rsyslog.com/e/2163 ]
2014-08-04T12:37:46.257733+10:00 <Server> rsyslogd-2163: epoll_ctl failed on fd 9999, id 0/0x7ffbca51e590, op 1 with File exists: File exists [try http ://www .rsyslog.com/e/2163 ]
2014-08-04T12:37:47.023105+10:00 <Server> rsyslogd-2163: message repeated 3 times: [epoll_ctl failed on fd 9999, id 0x07ffbca51e590, op 1 with File exists: File exists [try http ://www .rsyslog.com/e/2163 ]
2014-08-04T12:37:46.780713+10:00 <Server> rsyslogd-2163: epoll_ctl failed on fd 144, id 0/0x7ffbc6ba6570, op 1 with File exists: File exists [try http ://www .rsyslog.com/e/2163 ]
2014-08-04T12:37:46.789345+10:00 <Server> rsyslogd-2163: epoll_ctl failed on fd 9999, id 0/0x7ffbca51e590, op 1 with File exists: File exists [try http ://www .rsyslog.com/e/2163 ]



$ rsyslogd -v
rsyslogd 5.10.1, compiled with:
FEATURE_REGEXP: YES
FEATURE_LARGEFILE: NO
GSSAPI Kerberos 5 support: YES
FEATURE_DEBUG (debug build, slow code) NO
32bit Atomic operations supported: YES
64bit Atomic operations supported: YES
Runtime Instumentation (slow code): NO

$cat /etc/redhat-release
Red Hat Enteprise Linux Server release 6.3 (Santiago)

$ uname -a
Linux <Server FQDN> 2.6.32-279.5.1.el6.x86_64 #1 SMP Tue Jul 24 13:57:35 EDT 2012 x86_64 x86_64 GNU/Linux

$ cat /etc/security/limits.conf | egrep -v '#|$^'
root soft nofile 10200
root hard nofile 10240

$ cat /etc/rsyslog.conf | egrep -v '#|^$'
$MaxMessageSize 128k
$MaxOpenFiles 10000
$InputTCPMaxListeners 400
$InputTCPMaxSessions 4000
$FileOwner ictaudit
$FileGroup itdev
$DirOwner ictaudit
$DirGroup itdev
$FileCreateMode 0660
$DirCreateMode 0770
$RepeatedMsgContainsOriginalMsg on
$RepeatedMsgReduction on
$PstatsInterval 21600
$IncludeConfig /etc/rsyslog.d/*.conf
$template VLSecureFwdFmt, "%TIMESTAMP:::date-rfc3164% %HOSTNAME% _FilerVarLogSecure %TIMESTAMP:::date-rfc3164% %HOSTNAME% $syslogtag% %msg:::sp-if-no-1st-sp%%msg%\n"
$template VLMessagesFwdFmt, "%TIMESTAMP:::date-rfc3164% %HOSTNAME% _FilerVarLogMessages %TIMESTAMP:::date-rfc3164% %HOSTNAME% $syslogtag% %msg:::sp-if-no-1st-sp%%msg%\n"
$template VLYumFwdFmt, "%TIMESTAMP:::date-rfc3164% %HOSTNAME% _FilerVarLogYum %TIMESTAMP:::date-rfc3164% %HOSTNAME% $syslogtag% %msg:::sp-if-no-1st-sp%%msg%\n"
$template RFC5424, "pri:%pri-text:::% time:%TIMESTAMP:::date-subseconds,date-rfc3339% fhost:%FROMHOST% fip:%FROMHOST-IP% host:%HOSTNAME% tag:%syslogtag:::csv% pname:%programname:::csv% app:%app-name:::csv% pid:%procid:::% msgid:%msgid:::csv% sdata:%structured-data:::csv% msg:%msg:::sp-if-no-1st-sp%%msg:::drop-last-lf,csv%\n"
$template CycleFilerLog, "/data/rsyslog/$$YEAR%-%$MONTH%-%$DAY%/$fromhost%_%fromhost-ip%/filer.%$hour%.%$minute%"
$template CycleApplicationLog, "/data/rsyslog/$$YEAR%-%$MONTH%-%$DAY%/$fromhost%_%fromhost-ip%/app.%$hour%.%$minute%"
$template CycleGenricInbound, "/data/rsyslog/$$YEAR%-%$MONTH%-%$DAY%/$fromhost%_%fromhost-ip%/gen.%$hour%.%$minute%"
$template CycleCatchInbound, "/data/rsyslog/$$YEAR%-%$MONTH%-%$DAY%/$fromhost%_%fromhost-ip%/catch.%$hour%.%$minute%"
:syslogtag, startswith, "_Filer" -?CycleFilerLog
& ~
:syslogtag, startswith, "_ApplicationLog" -?CycleApplicationLog;RFC5424
& ~
if $fromhost-ip != '127.0.0.1' then -CycleCatchInbound;RFC5424
& ~
$RuleSet GenericInbound514
*.* -?CycleGenricInbound;RFC5424
& ~
$InputRELPServerRun 6171
$InputTCPServerRun 6171
$InputUDPServerBindRuleset GenericInbound514
$UDPServerRun 514
$RuleSet RSYSLOG_DefaultRuleSet
*.info;mail.none;authpriv.none;cron.none /var/log/messages
authpriv.* /var/log/secure
mail.* -/var/log/maillog
cron.* /var/log/cron
*.emerg :omusrmsg:*
uucp,news.crit /var/log/spooler
local7.* /var/log/boot.log
barryh
New
 
Posts: 1
Joined: Tue Aug 05, 2014 11:58 am

Re: Discussion for KB Entry 6921 - Syslogtag rsyslog-2163

Postby JohnE » Wed Aug 06, 2014 6:48 pm

We had the issue again a couple of days after I last posted.

Per Rainer's suggestion at "Thu Jul 17, 2014 5:14 am", we are making plans to upgrade the problematic instance (our busiest one) to version 8.x In the meantime while we test, plan, and my CR's clear, I have updated MaxOpenFiles to 4096 (it may or may not help). Also as fyi...I have have noted that our incoming message rate varies from 150/sec to 1500+/sec depending on the hour, however, I have not correlated the issue to our busiest hour.
JohnE
New
 
Posts: 3
Joined: Wed Jul 16, 2014 8:30 pm

Google Ads



Return to Windows Eventlog

Who is online

Users browsing this forum: No registered users and 3 guests

cron