#rsyslogd

[tikusrumput-blog]

Silly rsyslogd

Today I found that after upgrading my ubuntu VPS from 12.04 to 14.04 one of my cpu core are hung at 100%. I tried to htop it and found rsyslogd consuming 100% cpu.

My vps is OpenVZ, and short story I found how to fix it. Just run this command on your OpenVZ vps

service rsyslog stop

sed -i -e 's/^\$ModLoad imklog/#\$ModLoad imklog/g' /etc/rsyslog.conf

service rsyslog start

Quite easy, but dont ask me what second line means, I'm bad at explaining, lol

[eventenrichment]

New Post has been published on Event Enrichment.Org - http://www.eventenrichment.org/event-enrichment-unix-rsyslogd-imuxsock-message-drops/

New Post has been published on http://www.eventenrichment.org/event-enrichment-unix-rsyslogd-imuxsock-message-drops/

Event Enrichment : Unix : Rsyslogd : IMUXSOCK MESSAGE DROPS

This is the first in our sample Event Enrichment series!

While enjoying your shift in the quiet solitude of the NOC ;), you suddenly receive an alert from PagerDuty or your NMS. Depending on your level of expertise, you would typically need to open a runbook or Ops Wiki to determine how to handle the event.

Instead, let’s explore a different method, Event Enrichment, using the following syslog entry as our reference.

It all starts with an alert…

Jan 28 12:01:20 zenoss-mon rsyslogd-2177: imuxsock lost 5 messages from pid 1169 due to rate-limiting

This event has some useful information (we are losing messages which could be important, or event critical), but requires user intervention in order to investigate the problem. Now, assume that this same event arrives at the NOC already enriched with the steps required to handle the event. Mean Time to Repair (MTTR) would decrease given that the information required to properly triage the problem is already included in the initial alert.

Event Enrichments are composed of two components: remediation and escalation. Remediation consists of the steps necessary to rectify the problem, beginning with troubleshooting. The escalation includes the information to pass along as well as the intended recipient of said information (team or individual engineer)

REMEDIATION 

The first step in investigating this alert is to log into the device / server generating the error.

ops@noc-jump:~$ ssh ops@zenoss-mon Last login: Tue Jan 28 17:38:54 2014 from 172.25.230.5 [ops@zenoss-mon ~]#

The next step is to determine the process associated with the PID referenced in the alert.

Example

[ops@zenoss-mon ~]# ps aux | grep 1169 root 1169 0.2 0.1 203312 10368 ? S Jan23 22:48 /usr/sbin/snmpd -LS0-6d -Lf /dev/null -p /var/run/snmpd.pid

From the result of this command we can conclude that snmpd is generating more events than the configured rate-limiting threshold for rsyslogd (default is 200 events in a 5 second interval). On-call systems engineering will need to investigate the cause of this message suppression.

ESCALATION

Escalate to the on-call SysEng team using the PagerDuty SysEng Service (or other alerting mechanism) and include the following information:

Original Event Summary:  [Jan 28 12:01:20 zenoss-mon rsyslogd-2177: imuxsock lost 5 messages from pid 1169 due to rate-limiting]

Verified Findings:

This error is being generated due to an issue with /usr/sbin/snmpd.

[ops@zenoss-mon ~]# ps aux | grep 1169 root 1169 0.2 0.1 203312 10368 ? S Jan23 22:48 /usr/sbin/snmpd -LS0-6d -Lf /dev/null -p /var/run/snmpd.pid

      Adopting the Event Enrichment methodology enhances the standardization and scalability of your NOC and on-call processes.

Now check out the Beginner’s Guide to Event Enrichment to deepen your understanding of the methodology.

[myowan]

rsyslog/rsyslog2 troubleshooting

/sbin/rsyslog -f /etc/rsyslog.conf   (interactive) use debug: /sbin/rsyslogd -c3 -dn > logfile checks config file: /sbin/rsyslogd -f /etc/rsyslog.conf -N1

[lapismoon]

続 slapdのログの分離

/var/log/messagesがslapdのログで埋まってしまって、他の情報を発掘しないと見られないような状況になっていたので、slapdのログを単体のファイルに持つことにした。

インストールされているのはrsyslogdだが、書いてあることは大体syslogd互換の記法である。

<facility>.<priority> <action>

という感じの記法で、facilityは宛先みたいなもので、priorityはログレベルみたいなもの、actionはログを残す先を指定する。

slapdのデフォルトのfacilityはlocal4なので、

local4.*...

[lapismoon]

syslogdのログの分離の続き。

Filter Conditions - rsyslog.conf rsyslogによると、~ を書くとそれ以降のログを廃棄するらしい。

*.* /var/log/allmsgs-including-informational.log :msg, contains, "informational" ~ *.* /var/log/allmsgs-but-informational.log

Do not overlook the red tilde in line 2! In this sample, all messages are written to the file allmsgs-including-informational.log. Then, all messages containing the string "informational" are discarded. That means the config file lines below the "discard line" (number 2 in our sample) will not be applied to this message. Then, all remaining lines will also be written to the file allmsgs-but-informational.log.

この場合、メッセージに"informational"が含まれているログを廃棄になるので、同じように設定してやればいい。

local4.* -/var/log/slapd.log local4.* ~

で、& で直前のフィルターの使い回しができるので、

local4.* -/var/log/slapd.log & ~

と書ける。

前に書いたときから不安だったのが、local4としてばっさり切り離してしまったら、他にlocal4 facilityのものがきたときにどうするんだと思っていた。特定のプログラムだけ切り離すということもできるようなので(rsyslog.conf見て気付いた)、slapdだけ切り離すとこうなる。

if ($programname == 'slapd' ) \ then -/var/log/slapd.log & ~

これで安心して/var/log/messagesを眺めることができるぞ。

[lapismoon]

slapdのログの分離

/var/log/messagesがslapdのログで埋まってしまって、他の情報を発掘しないと見られないような状況になっていたので、slapdのログを単体のファイルに持つことにした。

インストールされているのはrsyslogdだが、書いてあることは大体syslogd互換の記法である。

<facility>.<priority>   <action>

という感じの記法で、facilityは宛先みたいなもので、priorityはログレベルみたいなもの、actionはログを残す先を指定する。

slapdのデフォルトのfacilityはlocal4なので、

local4.*    -/var/log/slapd.log

みたいに書けば良い。priorityはワイルドカードが使用可能。actionの - は非同期出力で、ログの量が多いものに同期出力をすると同期待ちが頻繁に起こって動作が遅くなるので指定しておくと良いらしい。

しかし、openSUSEのrsyslogdのルールには、全てのログを/var/log/messagesに保存するというのが存在する。

*.*;mail.none;news.none     -/var/log/messages

これが結構後半に書いてあるので、/etc/rsyslog.dの中に新しい設定を放り込んだとしても、このルールが適用されて、ログが2重に取られてしまう。

結局、/etc/rsyslog.dの中だけで解決する方法が分からなかったので、/etc/rsyslog.confを以下のやり方でいじって、除外ルールを追加することにした。

Manpage of SYSLOG.CONF

# info メッセージは /var/log/messages へ記録する。 # *.=info;\ mail,news.none /var/log/messages

この指示により syslogd は priority info の全てのメッセージをファイル /var/log/messages に記録する。ただし facility が mail と news の両方のメッセージは保存しない。

今回除外したいのはslapdのfacilityであるlocal4なので、以下のようになる。

*.*;mail.none;news.none;local4.none     -/var/log/messages

rsyslog.confに手を入れずに除外する方法をご存じの方はご一報を。