MonitorWare Knowledge Base

Hi @all,

i have a strange behavior of the rsyslogd server, when logrotate trys to reload the syslog server, the rsyslogd eats reproducable 100% cpu time and in the logs the message shown below appears (the select, and then, the last message repeated). this run through the whole sunday until i found out about it. if i do a RESTART instead of a RELOAD (e.g., no SIGHUP, but a STOP/START) then all works well, my setup is as follows:

rsyslog in virtual servers sitting on a single host-server. provided through openvz, installed on a debian host (the problem happend on 2 virtual servers at the daily logrotate cycle).
the virtual servers log into filesystem and forward to a syslog server, config file for rsyslogd is shown below.

This is what shows up in the log:

Feb 17 19:21:47 s10000 rsyslogd: [origin software="rsyslogd" swVersion="2.0.0" x-pid="10121"][x-configInfo udpReception=
"No" udpPort="514" tcpReception="No" tcpPort="0"] restart
Feb 17 19:21:47 s10000 rsyslogd:select: eb 17 19:21:47 sudo: ray : TTY=pts/0 ; PWD=/etc/cron.daily ; USER=root ; CO
MMAND=/usr/sbin/invoke-rc.d rsyslog reload
Feb 17 19:22:18 s10000 rsyslogd:last message repeated 644892 times
Feb 17 19:23:19 s10000 rsyslogd:last message repeated 1262563 times
Feb 17 19:24:20 s10000 rsyslogd:last message repeated 1261214 times
Feb 17 19:24:54 s10000 rsyslogd:last message repeated 715356 times

to be sure, i tried again 10 minutes later:
Feb 17 19:35:13 s10000 rsyslogd: [origin software="rsyslogd" swVersion="2.0.0" x-pid="12212"][x-configInfo udpReception=
"No" udpPort="514" tcpReception="No" tcpPort="0"] restart
Feb 17 19:35:13 s10000 rsyslogd:select: eb 17 19:35:13 sudo: ray : TTY=pts/0 ; PWD=/etc/cron.daily ; USER=root ; CO
MMAND=/usr/sbin/invoke-rc.d rsyslog reload
Feb 17 19:35:44 s10000 rsyslogd:last message repeated 628259 times
Feb 17 19:35:59 s10000 rsyslogd:last message repeated 306726 times

followed by a restart:
Feb 17 19:35:59 s10000 rsyslogd: [origin software="rsyslogd" swVersion="2.0.0" x-pid="12212"] exiting on signal 15.
Feb 17 19:35:59 s10000 rsyslogd: [origin software="rsyslogd" swVersion="2.0.0" x-pid="13823"][x-configInfo udpReception=
"No" udpPort="514" tcpReception="No" tcpPort="0"] restart
Feb 17 19:35:59 s10000 kernel: rklogd 2.0.0, log source = /proc/kmsg started.
--> at this point, all ok

for the time being i change my logrotate scripts to restart, but a sighup would be nicer thought .... do you have any explanation for this? if you need more information, or anything else, contact me, i'l be happy to help fix this bug.
best,
raimund



this is the debian part for the reload:
#
# Function that sends a SIGHUP to the daemon/service
#
do_reload() {
NAME=$1
PIDFILE=$2

start-stop-daemon --stop --signal HUP --quiet --pidfile $PIDFILE --name $NAME
return 0
}
where on debian the start-stop-daemon is an executable



my rsyslogd config:
# /etc/rsyslog.conf Configuration file for rsyslogd.
#
# For more information see
# /usr/share/doc/rsyslog/html/rsyslog_conf.html

#
# First some standard logfiles. Log by facility.
#
*.* @syslog-01


auth,authpriv.* /var/log/auth.log
*.*;auth,authpriv.none -/var/log/syslog
#cron.* /var/log/cron.log
daemon.* -/var/log/daemon.log
kern.* -/var/log/kern.log
lpr.* -/var/log/lpr.log
mail.* -/var/log/mail.log
user.* -/var/log/user.log

#
# Logging for the mail system. Split it up so that
# it is easy to write scripts to parse these files.
#
mail.info -/var/log/mail.info
mail.warn -/var/log/mail.warn
mail.err /var/log/mail.err

#
# Logging for INN news system
#
news.crit /var/log/news/news.crit
news.err /var/log/news/news.err
news.notice -/var/log/news/news.notice

#
# Some `catch-all' logfiles.
#
*.=debug;\
auth,authpriv.none;\
news.none;mail.none -/var/log/debug
*.=info;*.=notice;*.=warn;\
auth,authpriv.none;\
cron,daemon.none;\
mail,news.none -/var/log/messages

#
# Emergencies are sent to everybody logged in.
#
*.emerg *

#
# I like to have messages displayed on the console, but only on a virtual
# console I usually leave idle.
#
#daemon,mail.*;\
# news.=crit;news.=err;news.=notice;\
# *.=debug;*.=info;\
# *.=notice;*.=warn /dev/tty8

# The named pipe /dev/xconsole is for the `xconsole' utility. To use it,
# you must invoke `xconsole' with the `-file' option:
#
# $ xconsole -file /dev/xconsole [...]
#
# NOTE: adjust the list below, or you'll go crazy if you have a reasonably
# busy site..
#
daemon.*;mail.*;\
news.err;\
*.=debug;*.=info;\
*.=notice;*.=warn |/dev/xconsole
#
# Include all config files in /etc/rsyslog.d/
#
$IncludeConfig /etc/rsyslog.d/*.conf

• Custom written rsyslog.conf?
• Maintenance Contract?
• Installation support?

I tried to SIGHUP the rsyslogd while running in -d (debug) mode, here it seems to work like expacted (as far as i can figure it out from the debug output, which is rather long, but i paste all if it, just to be sure):

i marked the (for me) relevant part's bold, interesting is also very send to my syslog server has a following errormessage, but the messages are delivered correctly ... this is also something which should be pinned down.

ray@web-01:~$ sudo invoke-rc.d rsyslog restart
Stopping enhanced syslogd: rklogd rsyslogd.
Starting enhanced syslogd: rsyslogdStarting.
-1210554688: rsyslog 2.0.0.
-1210554688: Called init.
-1210554688: Unloading non-static modules.
-1210554688: Clearing templates.
-1210554688: cfline: '*.* @syslog-01'
-1210554688: - traditional PRI filter
-1210554688: symbolic name: * ==> 255
-1210554688: tried selector action for builtin-file: -2001
-1210554688: tried selector action for builtin-fwd: 0
-1210554688: Module builtin-fwd processed this config line.
-1210554688: template: ' StdFwdFmt' assigned
-1210554688: cfline: 'auth,authpriv.* /var/log/auth.log'
-1210554688: selector line successfully processed
-1210554688: - traditional PRI filter
-1210554688: symbolic name: * ==> 255
-1210554688: symbolic name: auth ==> 32
-1210554688: symbolic name: authpriv ==> 80
-1210554688: tried selector action for builtin-file: 0
-1210554688: Module builtin-file processed this config line.
-1210554688: template: ' TradFmt' assigned
-1210554688: cfline: '*.*;auth,authpriv.none -/var/log/syslog'
-1210554688: selector line successfully processed
-1210554688: - traditional PRI filter
-1210554688: symbolic name: * ==> 255
-1210554688: symbolic name: none ==> 16
-1210554688: symbolic name: auth ==> 32
-1210554688: symbolic name: authpriv ==> 80
-1210554688: tried selector action for builtin-file: 0
-1210554688: Module builtin-file processed this config line.
-1210554688: template: ' TradFmt' assigned
-1210554688: cfline: 'daemon.* -/var/log/daemon.log'
-1210554688: selector line successfully processed
-1210554688: - traditional PRI filter
-1210554688: symbolic name: * ==> 255
-1210554688: symbolic name: daemon ==> 24
-1210554688: tried selector action for builtin-file: 0
-1210554688: Module builtin-file processed this config line.
-1210554688: template: ' TradFmt' assigned
-1210554688: cfline: 'kern.* -/var/log/kern.log'
-1210554688: selector line successfully processed
-1210554688: - traditional PRI filter
-1210554688: symbolic name: * ==> 255
-1210554688: symbolic name: kern ==> 0
-1210554688: tried selector action for builtin-file: 0
-1210554688: Module builtin-file processed this config line.
-1210554688: template: ' TradFmt' assigned
-1210554688: cfline: 'lpr.* -/var/log/lpr.log'
-1210554688: selector line successfully processed
-1210554688: - traditional PRI filter
-1210554688: symbolic name: * ==> 255
-1210554688: symbolic name: lpr ==> 48
-1210554688: tried selector action for builtin-file: 0
-1210554688: Module builtin-file processed this config line.
-1210554688: template: ' TradFmt' assigned
-1210554688: cfline: 'mail.* -/var/log/mail.log'
-1210554688: selector line successfully processed
-1210554688: - traditional PRI filter
-1210554688: symbolic name: * ==> 255
-1210554688: symbolic name: mail ==> 16
-1210554688: tried selector action for builtin-file: 0
-1210554688: Module builtin-file processed this config line.
-1210554688: template: ' TradFmt' assigned
-1210554688: cfline: 'user.* -/var/log/user.log'
-1210554688: selector line successfully processed
-1210554688: - traditional PRI filter
-1210554688: symbolic name: * ==> 255
-1210554688: symbolic name: user ==> 8
-1210554688: tried selector action for builtin-file: 0
-1210554688: Module builtin-file processed this config line.
-1210554688: template: ' TradFmt' assigned
-1210554688: cfline: 'mail.info -/var/log/mail.info'
-1210554688: selector line successfully processed
-1210554688: - traditional PRI filter
-1210554688: symbolic name: info ==> 6
-1210554688: symbolic name: mail ==> 16
-1210554688: tried selector action for builtin-file: 0
-1210554688: Module builtin-file processed this config line.
-1210554688: template: ' TradFmt' assigned
-1210554688: cfline: 'mail.warn -/var/log/mail.warn'
-1210554688: selector line successfully processed
-1210554688: - traditional PRI filter
-1210554688: symbolic name: warn ==> 4
-1210554688: symbolic name: mail ==> 16
-1210554688: tried selector action for builtin-file: 0
-1210554688: Module builtin-file processed this config line.
-1210554688: template: ' TradFmt' assigned
-1210554688: cfline: 'mail.err /var/log/mail.err'
-1210554688: selector line successfully processed
-1210554688: - traditional PRI filter
-1210554688: symbolic name: err ==> 3
-1210554688: symbolic name: mail ==> 16
-1210554688: tried selector action for builtin-file: 0
-1210554688: Module builtin-file processed this config line.
-1210554688: template: ' TradFmt' assigned
-1210554688: cfline: 'news.crit /var/log/news/news.crit'
-1210554688: selector line successfully processed
-1210554688: - traditional PRI filter
-1210554688: symbolic name: crit ==> 2
-1210554688: symbolic name: news ==> 56
-1210554688: tried selector action for builtin-file: 0
-1210554688: Module builtin-file processed this config line.
-1210554688: template: ' TradFmt' assigned
-1210554688: cfline: 'news.err /var/log/news/news.err'
-1210554688: selector line successfully processed
-1210554688: - traditional PRI filter
-1210554688: symbolic name: err ==> 3
-1210554688: symbolic name: news ==> 56
-1210554688: tried selector action for builtin-file: 0
-1210554688: Module builtin-file processed this config line.
-1210554688: template: ' TradFmt' assigned
-1210554688: cfline: 'news.notice -/var/log/news/news.notice'
-1210554688: selector line successfully processed
-1210554688: - traditional PRI filter
-1210554688: symbolic name: notice ==> 5
-1210554688: symbolic name: news ==> 56
-1210554688: tried selector action for builtin-file: 0
-1210554688: Module builtin-file processed this config line.
-1210554688: template: ' TradFmt' assigned
-1210554688: cfline: '*.=debug;auth,authpriv.none;news.none;mail.none -/var/log/debug'
-1210554688: selector line successfully processed
-1210554688: - traditional PRI filter
-1210554688: symbolic name: debug ==> 7
-1210554688: symbolic name: none ==> 16
-1210554688: symbolic name: auth ==> 32
-1210554688: symbolic name: authpriv ==> 80
-1210554688: symbolic name: none ==> 16
-1210554688: symbolic name: news ==> 56
-1210554688: symbolic name: none ==> 16
-1210554688: symbolic name: mail ==> 16
-1210554688: tried selector action for builtin-file: 0
-1210554688: Module builtin-file processed this config line.
-1210554688: template: ' TradFmt' assigned
-1210554688: cfline: '*.=info;*.=notice;*.=warn;auth,authpriv.none;cron,daemon.none;mail,news.none -/var/log/messages'
-1210554688: selector line successfully processed
-1210554688: - traditional PRI filter
-1210554688: symbolic name: info ==> 6
-1210554688: symbolic name: notice ==> 5
-1210554688: symbolic name: warn ==> 4
-1210554688: symbolic name: none ==> 16
-1210554688: symbolic name: auth ==> 32
-1210554688: symbolic name: authpriv ==> 80
-1210554688: symbolic name: none ==> 16
-1210554688: symbolic name: cron ==> 72
-1210554688: symbolic name: daemon ==> 24
-1210554688: symbolic name: none ==> 16
-1210554688: symbolic name: mail ==> 16
-1210554688: symbolic name: news ==> 56
-1210554688: tried selector action for builtin-file: 0
-1210554688: Module builtin-file processed this config line.
-1210554688: template: ' TradFmt' assigned
-1210554688: cfline: '*.emerg *'
-1210554688: selector line successfully processed
-1210554688: - traditional PRI filter
-1210554688: symbolic name: emerg ==> 0
-1210554688: tried selector action for builtin-file: -2001
-1210554688: tried selector action for builtin-fwd: -2001
-1210554688: tried selector action for builtin-shell: -2001
-1210554688: tried selector action for builtin-discard: -2001
-1210554688: write-alltried selector action for builtin-usrmsg: 0
-1210554688: Module builtin-usrmsg processed this config line.
-1210554688: template: ' WallFmt' assigned
-1210554688: cfline: 'daemon.*;mail.*;news.err;*.=debug;*.=info;*.=notice;*.=warn |/dev/xconsole'
-1210554688: selector line successfully processed
-1210554688: - traditional PRI filter
-1210554688: symbolic name: * ==> 255
-1210554688: symbolic name: daemon ==> 24
-1210554688: symbolic name: * ==> 255
-1210554688: symbolic name: mail ==> 16
-1210554688: symbolic name: err ==> 3
-1210554688: symbolic name: news ==> 56
-1210554688: symbolic name: debug ==> 7
-1210554688: symbolic name: info ==> 6
-1210554688: symbolic name: notice ==> 5
-1210554688: symbolic name: warn ==> 4
-1210554688: tried selector action for builtin-file: 0
-1210554688: Module builtin-file processed this config line.
-1210554688: template: ' TradFmt' assigned
-1210554688: cfline: '$IncludeConfig /etc/rsyslog.d/*.conf'
-1210554688: selector line successfully processed
-1210554688: Opened UNIX socket `/dev/log' (fd 3).
-1210554688: Opened 2 syslog UDP port(s).
-1210554688: Worker thread started with state 0.

Active selectors:
Selector 1:
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF
Actions:
builtin-fwd: syslog-01
Instance data: 0x8069648
RepeatedMsgReduction: 1
Resume Interval: 30
Suspended: 0
Disabled: 0
Exec only when previous is suspended: 0



Selector 2:
X X X X FF X X X X X FF X X X X X X X X X X X X X X
Actions:
builtin-file: /var/log/auth.log
Instance data: 0x8069f88
RepeatedMsgReduction: 1
Resume Interval: 30
Suspended: 0
Disabled: 0
Exec only when previous is suspended: 0



Selector 3:
FF FF FF FF X FF FF FF FF FF X FF FF FF FF FF FF FF FF FF FF FF FF FF FF
Actions:
builtin-file: /var/log/syslog
Instance data: 0x806a190
RepeatedMsgReduction: 1
Resume Interval: 30
Suspended: 0
Disabled: 0
Exec only when previous is suspended: 0



Selector 4:
X X X FF X X X X X X X X X X X X X X X X X X X X X
Actions:
builtin-file: /var/log/daemon.log
Instance data: 0x806a398
RepeatedMsgReduction: 1
Resume Interval: 30
Suspended: 0
Disabled: 0
Exec only when previous is suspended: 0



Selector 5:
FF X X X X X X X X X X X X X X X X X X X X X X X X
Actions:
builtin-file: /var/log/kern.log
Instance data: 0x806a5a0
RepeatedMsgReduction: 1
Resume Interval: 30
Suspended: 0
Disabled: 0
Exec only when previous is suspended: 0



Selector 6:
X X X X X X FF X X X X X X X X X X X X X X X X X X
Actions:
builtin-file: /var/log/lpr.log
Instance data: 0x806a7a8
RepeatedMsgReduction: 1
Resume Interval: 30
Suspended: 0
Disabled: 0
Exec only when previous is suspended: 0



Selector 7:
X X FF X X X X X X X X X X X X X X X X X X X X X X
Actions:
builtin-file: /var/log/mail.log
Instance data: 0x806a9b0
RepeatedMsgReduction: 1
Resume Interval: 30
Suspended: 0
Disabled: 0
Exec only when previous is suspended: 0



Selector 8:
X FF X X X X X X X X X X X X X X X X X X X X X X X
Actions:
builtin-file: /var/log/user.log
Instance data: 0x806abb8
RepeatedMsgReduction: 1
Resume Interval: 30
Suspended: 0
Disabled: 0
Exec only when previous is suspended: 0



Selector 9:
X X 7F X X X X X X X X X X X X X X X X X X X X X X
Actions:
builtin-file: /var/log/mail.info
Instance data: 0x806adc0
RepeatedMsgReduction: 1
Resume Interval: 30
Suspended: 0
Disabled: 0
Exec only when previous is suspended: 0



Selector 10:
X X 1F X X X X X X X X X X X X X X X X X X X X X X
Actions:
builtin-file: /var/log/mail.warn
Instance data: 0x806afc8
RepeatedMsgReduction: 1
Resume Interval: 30
Suspended: 0
Disabled: 0
Exec only when previous is suspended: 0



Selector 11:
X X F X X X X X X X X X X X X X X X X X X X X X X
Actions:
builtin-file: /var/log/mail.err
Instance data: 0x806b1d0
RepeatedMsgReduction: 1
Resume Interval: 30
Suspended: 0
Disabled: 0
Exec only when previous is suspended: 0



Selector 12:
X X X X X X X 7 X X X X X X X X X X X X X X X X X
Actions:
builtin-file: /var/log/news/news.crit
Instance data: 0x806b3d8
RepeatedMsgReduction: 1
Resume Interval: 30
Suspended: 0
Disabled: 0
Exec only when previous is suspended: 0



Selector 13:
X X X X X X X F X X X X X X X X X X X X X X X X X
Actions:
builtin-file: /var/log/news/news.err
Instance data: 0x806b5e0
RepeatedMsgReduction: 1
Resume Interval: 30
Suspended: 0
Disabled: 0
Exec only when previous is suspended: 0



Selector 14:
X X X X X X X 3F X X X X X X X X X X X X X X X X X
Actions:
builtin-file: /var/log/news/news.notice
Instance data: 0x806b7e8
RepeatedMsgReduction: 1
Resume Interval: 30
Suspended: 0
Disabled: 0
Exec only when previous is suspended: 0



Selector 15:
80 80 X 80 X 80 80 X 80 80 X 80 80 80 80 80 80 80 80 80 80 80 80 80 80
Actions:
builtin-file: /var/log/debug
Instance data: 0x806b9f0
RepeatedMsgReduction: 1
Resume Interval: 30
Suspended: 0
Disabled: 0
Exec only when previous is suspended: 0



Selector 16:
70 70 X X X 70 70 X 70 X X 70 70 70 70 70 70 70 70 70 70 70 70 70 70
Actions:
builtin-file: /var/log/messages
Instance data: 0x806bbf8
RepeatedMsgReduction: 1
Resume Interval: 30
Suspended: 0
Disabled: 0
Exec only when previous is suspended: 0



Selector 17:
1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1
Actions:
builtin-usrmsg:
Instance data: 0x806be00
RepeatedMsgReduction: 1
Resume Interval: 30
Suspended: 0
Disabled: 0
Exec only when previous is suspended: 0



Selector 18:
F0 F0 FF FF F0 F0 F0 FF F0 F0 F0 F0 F0 F0 F0 F0 F0 F0 F0 F0 F0 F0 F0 F0 F0
Actions:
builtin-file: /dev/xconsole
Instance data: 0x806c188
RepeatedMsgReduction: 1
Resume Interval: 30
Suspended: 0
Disabled: 0
Exec only when previous is suspended: 0




-1210554688: Template: Name=' TradFmt'
-1210554688: Entry(8067a50): type 2, (FIELD), value: 'TIMESTAMP'
-1210554688: Entry(8067ac8): type 1, (CONSTANT), value: ' '
-1210554688: Entry(8067b38): type 2, (FIELD), value: 'HOSTNAME'
-1210554688: Entry(8067b88): type 1, (CONSTANT), value: ' '
-1210554688: Entry(8067c20): type 2, (FIELD), value: 'syslogtag'
-1210554688: Entry(8067c70): type 2, (FIELD), value: 'msg' [drop last LF in msg]
-1210554688: Entry(8067cc0): type 1, (CONSTANT), value: '
'
-1210554688: Template: Name=' WallFmt'
-1210554688: Entry(8067d50): type 1, (CONSTANT), value: '
Message from syslogd@'
-1210554688: Entry(8067dc0): type 2, (FIELD), value: 'HOSTNAME'
-1210554688: Entry(8067e10): type 1, (CONSTANT), value: ' at '
-1210554688: Entry(8067ea8): type 2, (FIELD), value: 'timegenerated'
-1210554688: Entry(8067ef8): type 1, (CONSTANT), value: ' ...
'
-1210554688: Entry(8067f48): type 2, (FIELD), value: 'syslogtag'
-1210554688: Entry(8067f98): type 2, (FIELD), value: 'msg'
-1210554688: Entry(8068030): type 1, (CONSTANT), value: '
'
-1210554688: Template: Name=' StdFwdFmt'
-1210554688: Entry(80680a0): type 1, (CONSTANT), value: '<'
-1210554688: Entry(8068100): type 2, (FIELD), value: 'PRI'
-1210554688: Entry(8068150): type 1, (CONSTANT), value: '>'
-1210554688: Entry(80681e8): type 2, (FIELD), value: 'TIMESTAMP'
-1210554688: Entry(8068238): type 1, (CONSTANT), value: ' '
-1210554688: Entry(8068288): type 2, (FIELD), value: 'HOSTNAME'
-1210554688: Entry(80682d8): type 1, (CONSTANT), value: ' '
-1210554688: Entry(8068370): type 2, (FIELD), value: 'syslogtag'
-1210554688: Entry(80683c0): type 2, (FIELD), value: 'msg'
-1210554688: Template: Name=' StdUsrMsgFmt'
-1210554688: Entry(8068450): type 1, (CONSTANT), value: ' '
-1210554688: Entry(80684b0): type 2, (FIELD), value: 'syslogtag'
-1210554688: Entry(8068500): type 2, (FIELD), value: 'msg'
-1210554688: Entry(8068598): type 1, (CONSTANT), value: '
'
-1210554688: Template: Name=' StdDBFmt' [SQL-Format (MySQL)]
-1210554688: Entry(8068650): type 1, (CONSTANT), value: 'insert into SystemEvents (Message, Facility, FromHost, Priority, DeviceReportedTime, ReceivedAt, InfoUnitID, SysLogTag) values (''
-1210554688: Entry(8068728): type 2, (FIELD), value: 'msg'
-1210554688: Entry(8068778): type 1, (CONSTANT), value: '', '
-1210554688: Entry(80687c8): type 2, (FIELD), value: 'syslogfacility'
-1210554688: Entry(8068818): type 1, (CONSTANT), value: ', ''
-1210554688: Entry(8068878): type 2, (FIELD), value: 'HOSTNAME'
-1210554688: Entry(80688c8): type 1, (CONSTANT), value: '', '
-1210554688: Entry(8068960): type 2, (FIELD), value: 'syslogpriority'
-1210554688: Entry(80689b0): type 1, (CONSTANT), value: ', ''
-1210554688: Entry(8068a00): type 2, (FIELD), value: 'timereported' [Format as MySQL-Date]
-1210554688: Entry(8068a50): type 1, (CONSTANT), value: '', ''
-1210554688: Entry(8068af0): type 2, (FIELD), value: 'timegenerated' [Format as MySQL-Date]
-1210554688: Entry(8068b40): type 1, (CONSTANT), value: '', '
-1210554688: Entry(8068b90): type 2, (FIELD), value: 'iut'
-1210554688: Entry(8068be0): type 1, (CONSTANT), value: ', ''
-1210554688: Entry(8068c78): type 2, (FIELD), value: 'syslogtag'
-1210554688: Entry(8068cc8): type 1, (CONSTANT), value: '')'
-1210554688: Template: Name=' StdPgSQLFmt' [SQL-Format (standard SQL)]
-1210554688: Entry(8068d98): type 1, (CONSTANT), value: 'insert into SystemEvents (Message, Facility, FromHost, Priority, DeviceReportedTime, ReceivedAt, InfoUnitID, SysLogTag) values (''
-1210554688: Entry(8068e70): type 2, (FIELD), value: 'msg'
-1210554688: Entry(8068ec0): type 1, (CONSTANT), value: '', '
-1210554688: Entry(8068f10): type 2, (FIELD), value: 'syslogfacility'
-1210554688: Entry(8068f60): type 1, (CONSTANT), value: ', ''
-1210554688: Entry(8068fc0): type 2, (FIELD), value: 'HOSTNAME'
-1210554688: Entry(8069010): type 1, (CONSTANT), value: '', '
-1210554688: Entry(80690a8): type 2, (FIELD), value: 'syslogpriority'
-1210554688: Entry(80690f8): type 1, (CONSTANT), value: ', ''
-1210554688: Entry(8069148): type 2, (FIELD), value: 'timereported' [Format as PgSQL-Date]
-1210554688: Entry(8069198): type 1, (CONSTANT), value: '', ''
-1210554688: Entry(8069238): type 2, (FIELD), value: 'timegenerated' [Format as PgSQL-Date]
-1210554688: Entry(8069288): type 1, (CONSTANT), value: '', '
-1210554688: Entry(80692d8): type 2, (FIELD), value: 'iut'
-1210554688: Entry(8069328): type 1, (CONSTANT), value: ', ''
-1210554688: Entry(80693c0): type 2, (FIELD), value: 'syslogtag'
-1210554688: Entry(8069410): type 1, (CONSTANT), value: '')'
-1210554688: Loaded Module: Name='builtin-file', IFVersion=1, type=output module.
-1210554688: Entry points:
-1210554688: queryEtryPt: 0x805c850
-1210554688: doAction: 0x805d510
-1210554688: parseSelectorAct: 0x805ce00
-1210554688: dbgPrintInstInfo: 0x805cb00
-1210554688: freeInstance: 0x805ca90
-1210554688:
-1210554688: Loaded Module: Name='builtin-fwd', IFVersion=1, type=output module.
-1210554688: Entry points:
-1210554688: queryEtryPt: 0x805a870
-1210554688: doAction: 0x805b260
-1210554688: parseSelectorAct: 0x805adf0
-1210554688: dbgPrintInstInfo: 0x805add0
-1210554688: freeInstance: 0x805ad60
-1210554688:
-1210554688: Loaded Module: Name='builtin-shell', IFVersion=1, type=output module.
-1210554688: Entry points:
-1210554688: queryEtryPt: 0x8059c10
-1210554688: doAction: 0x8059f40
-1210554688: parseSelectorAct: 0x8059e10
-1210554688: dbgPrintInstInfo: 0x8059df0
-1210554688: freeInstance: 0x8059dd0
-1210554688:
-1210554688: Loaded Module: Name='builtin-discard', IFVersion=1, type=output module.
-1210554688: Entry points:
-1210554688: queryEtryPt: 0x805db70
-1210554688: doAction: 0x805dac0
-1210554688: parseSelectorAct: 0x805dd50
-1210554688: dbgPrintInstInfo: 0x805da90
-1210554688: freeInstance: 0x805dd30
-1210554688:
-1210554688: Loaded Module: Name='builtin-usrmsg', IFVersion=1, type=output module.
-1210554688: Entry points:
-1210554688: queryEtryPt: 0x805a060
-1210554688: doAction: 0x805a760
-1210554688: parseSelectorAct: 0x805a280
-1210554688: dbgPrintInstInfo: 0x805a240
-1210554688: freeInstance: 0x805a220
-1210554688:

Sytem Line Configuration Commands:
Command 'dynafilecachesize':
type : 6
pData: 0x0
Hdlr : 0x805cbe0
Owner: 0x805c580

Command 'dirowner':
type : 2
pData: 0x8065db8
Hdlr : 0x0
Owner: 0x805c580

Command 'dirgroup':
type : 3
pData: 0x8065dbc
Hdlr : 0x0
Owner: 0x805c580

Command 'fileowner':
type : 2
pData: 0x8065db0
Hdlr : 0x0
Owner: 0x805c580

Command 'filegroup':
type : 3
pData: 0x8065db4
Hdlr : 0x0
Owner: 0x805c580

Command 'dircreatemode':
type : 5
pData: 0x8065b70
Hdlr : 0x0
Owner: 0x805c580

Command 'filecreatemode':
type : 5
pData: 0x8065b74
Hdlr : 0x0
Owner: 0x805c580

Command 'createdirs':
type : 4
pData: 0x8065dc0
Hdlr : 0x0
Owner: 0x805c580

Command 'failonchownfailure':
type : 4
pData: 0x8065dac
Hdlr : 0x0
Owner: 0x805c580

Command 'resetconfigvariables':
type : 1
pData: 0x0
Hdlr : 0x805c510
Owner: 0x805c580

type : 1
pData: 0x0
Hdlr : 0x804ced0
Owner: 0x0

Command 'mainmsgqueuesize':
type : 6
pData: 0x8065e44
Hdlr : 0x0
Owner: 0x0

Command 'repeatedmsgreduction':
type : 4
pData: 0x8065cac
Hdlr : 0x0
Owner: 0x0

Command 'actionexeconlywhenpreviousissuspended':
type : 4
pData: 0x8065cb0
Hdlr : 0x0
Owner: 0x0

Command 'actionresumeinterval':
type : 6
pData: 0x0
Hdlr : 0x804d050
Owner: 0x0

Command 'controlcharacterescapeprefix':
type : 7
pData: 0x8065799
Hdlr : 0x0
Owner: 0x0

Command 'escapecontrolcharactersonreceive':
type : 4
pData: 0x8065ca8
Hdlr : 0x0
Owner: 0x0

Command 'dropmsgswithmaliciousdnsptrrecords':
type : 4
pData: 0x8065c1c
Hdlr : 0x0
Owner: 0x0

Command 'droptrailinglfonreception':
type : 4
pData: 0x806579c
Hdlr : 0x0
Owner: 0x0

Command 'template':
type : 1
pData: 0x0
Hdlr : 0x80517f0
Owner: 0x0

Command 'outchannel':
type : 1
pData: 0x1
Hdlr : 0x80517f0
Owner: 0x0

Command 'allowedsender':
type : 1
pData: 0x2
Hdlr : 0x80517f0
Owner: 0x0

Command 'modload':
type : 1
pData: 0x0
Hdlr : 0x804f730
Owner: 0x0

Command 'includeconfig':
type : 1
pData: 0x0
Hdlr : 0x80508f0
Owner: 0x0

Command 'umask':
type : 5
pData: 0x0
Hdlr : 0x804d550
Owner: 0x0

Command 'debugprinttemplatelist':
type : 4
pData: 0x80657a0
Hdlr : 0x0
Owner: 0x0

Command 'debugprintmodulelist':
type : 4
pData: 0x80657a4
Hdlr : 0x0
Owner: 0x0

Command 'debugprintcfsyslinehandlerlist':
type : 4
pData: 0x80657a8
Hdlr : 0x0
Owner: 0x0

Command 'moddir':
type : 8
pData: 0x8065c58
Hdlr : 0x0
Owner: 0x0



Allowed UDP Senders:
No restrictions set.

Allowed TCP Senders:
No restrictions set.

Messages with malicious PTR DNS Records are not dropped.
Control characters are replaced upon reception.
Control character escape sequence prefix is '#'.
Main queue size 10000 messages.
-1210554688: logmsg: syslog.info<46>, flags 5, from '', msg [origin software="rsyslogd" swVersion="2.0.0" x-pid="20176"][x-configInfo udpReception="No" udpPort="514" tcpReception="No" tcpPort="0"] restart
-1210554688: Message has legacy syslog format.
-1210554688: EnqueueMsg signaled condition (0)
-1210554688: restarted.
-1210554688: Debugging enabled, SIGUSR1 to turn off debugging.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210721360: Lone worker is running...
-1210721360: Called fprintlog, logging to builtin-fwd syslog-01:514/udp
-1210721360: sendto() error: 101 = Network is unreachable.
-1210721360: Called fprintlog, logging to builtin-file (/var/log/syslog)
-1210721360: Called fprintlog, logging to builtin-file (/var/log/messages)
-1210721360: Called fprintlog, logging to builtin-file (/dev/xconsole)
-1210721360: singleWorker: queue EMPTY, waiting for next message.




-1210554688:
Successful select, descriptor count = 1, Activity on: 3
-1210554688: Message from UNIX socket: #3
-1210554688: Message length: 103, File descriptor: 3.
-1210554688: logmsg: authpriv.notice<85>, flags 2, from 's10000', msg Feb 18 13:45:20 sudo: ray : TTY=pts/1 ; PWD=/home/ray ; USER=root ; COMMAND=/bin/kill -1 19947
-1210554688: Message has legacy syslog format.
-1210554688: EnqueueMsg signaled condition (0)
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210721360: Lone worker is running...
-1210721360: Called fprintlog, logging to builtin-fwd syslog-01:514/udp
-1210721360: sendto() error: 101 = Network is unreachable.
-1210721360: Called fprintlog, logging to builtin-file (/var/log/auth.log)
-1210721360: Called fprintlog, logging to builtin-file (/dev/xconsole)
-1210721360: singleWorker: queue EMPTY, waiting for next message.
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688:
Successful select, descriptor count = 1, Activity on: 3
-1210554688: Message from UNIX socket: #3
-1210554688: Message length: 103, File descriptor: 3.
-1210554688: logmsg: authpriv.notice<85>, flags 2, from 's10000', msg Feb 18 13:57:18 sudo: ray : TTY=pts/1 ; PWD=/home/ray ; USER=root ; COMMAND=/bin/kill -1 19947
-1210554688: Message has legacy syslog format.
-1210554688: EnqueueMsg signaled condition (0)
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210721360: Lone worker is running...
-1210721360: msg repeated 1 times, 718 sec of 30.
-1210721360: Called fprintlog, logging to builtin-fwd syslog-01:514/udp
-1210721360: sendto() error: 101 = Network is unreachable.
-1210721360: msg repeated 1 times, 718 sec of 30.
-1210721360: Called fprintlog, logging to builtin-file (/var/log/auth.log)
-1210721360: msg repeated 1 times, 718 sec of 30.
-1210721360: Called fprintlog, logging to builtin-file (/dev/xconsole)
-1210721360: singleWorker: queue EMPTY, waiting for next message.
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: Select interrupted.
-1210554688: ----------------------------------------
-1210554688: Calling select, active file descriptors (max 3): 3
-1210554688: DoDie called.
-1210554688: Select interrupted.
-1210554688: exiting on signal 2
-1210554688: logmsg: syslog.info<46>, flags 5, from '', msg [origin software="rsyslogd" swVersion="2.0.0" x-pid="20176"] exiting on signal 2.
-1210554688: Message has legacy syslog format.
-1210554688: EnqueueMsg signaled condition (0)
-1210554688: Freeing log structures.
-1210554688: Initiating worker thread shutdown sequence...
-1210721360: Lone worker is running...
-1210721360: Called fprintlog, logging to builtin-fwd syslog-01:514/udp
-1210721360: sendto() error: 101 = Network is unreachable.
-1210721360: Called fprintlog, logging to builtin-file (/var/log/syslog)
-1210721360: Called fprintlog, logging to builtin-file (/var/log/messages)
-1210721360: Called fprintlog, logging to builtin-file (/dev/xconsole)
-1210721360: Worker thread terminates
-1210554688: Worker thread terminated.
-1210554688: Unloading module builtin-file
-1210554688: Unloading module builtin-fwd
-1210554688: Unloading module builtin-shell
-1210554688: Unloading module builtin-discard
-1210554688: Unloading module builtin-usrmsg
-1210554688: Clean shutdown completed, bye.
rklogd.

Hi Raimund,

thanks for posting to the forum

Rainer

As this seems to show relatively nothing about my primary problem i tried the an strace call on the rsyslogd, while running normally and while doing a sig-hup ... it seems to be some sort of racecondition or problem with a futex (semaphor?) ... or maybe this are normal messages, i send the strace output to rainer because it's a 113 MB file (ziped is also 2.4 MB, so i do not paste it here)

out of a hunch i also tried to disable the forwarding of the messages to my syslog server, and now the problem seems to be solved, e.g., no trillions of messages and no cpu hogging, while reloading.

then i added the forward again.

zap, rsyslogd changes into the ressource-hungry-message-crying-baby again ...

I am still looking at the output. All of that points into the direction of the send error. Maybe it's even fixed. We had some incorrectly init of the network send code. Could you please try the latest stable build. I guess it will make the problem disappear.

Download here:

http://www.rsyslog.com/Downloads-req-vi ... id-1.phtml

Current is 2.02.

Rainer

Hi Rainer,

ok, i will try to get the debian-source package and update it to 2.0.2 and test this again, and i'm currently sending an email to the debian maintainer of the rsyslog package ...

as i hopfully will have time to do this today in the night, i will paste my succes/failure then or tomorrow!

thx and regards

Raimund

Raimund,

great, please keep us posted. AFAIK there should be Debian packages for 2.0.2 - but I may be wrong

Rainer

Yes but in debian everything is a bit different, 2.0.2 package are existing, but in the development branch, to get them into stable they have to be recompiled for stable (etch) and moved to the so called "backport" repository to be accessible for the debian stable-user crowed

OK, OK, I shouldn't talk about distros - I am pretty clueless here

Rainer

The debian maintainer for the rsyslog package responded very quickly (thank you, michael biebl) and he provided me with a new test package for the backport system whith a 2.0.2 version.

and i am happy to be able to say that the problem is solved now, the package should soon be available in the debian backport repository!

best regards

Raimund

just in case somebody else has this problem also, the package will appear in the backports in a view days, if you are interested, checkout this link, it's the way of how debian works, if in the meantime somebody wants the package, drop me a note and i can email it to you.

http://release.debian.org/migration/tes ... ge=rsyslog

best, raimund

Hi Raimund,

I am glad the issue is solved. And, I know Michael Biebl very well. He does a *superb* job. He is also a frequent contributor to the rsyslog project itself

Rainer