Mailing List Archive

Syslog logging taking too much disk write?
I have a semi busy syslog server which logs about 40 or 50 lines per
second. I noticed using dstat that it's taking a TON of disk write.
In the megaBYTES per second range. This seems extremely high to me
so I wrote a script to test it.

http://www.perturb.org/code/log_lines.pl

First download dstat, gkrellm, or iostat and look at what your
normal disk write is per second. On my underused desktop it hovers
around zero or maybe 25KB/s per second.

If I run my script and tell it to log 10 lines to syslog per second

perl log_lines.pl 10

the write usage spikes up to ~160KB/s. We're only writing about 740
bytes of data per second so why is the disk write so high?

If I tell my script to instead log to a local file in /tmp at 10
lines per second

perl log_lines.pl 10 -t

The write usage spikes to ~120KB/s about once every 5 seconds (as
the buffer fills up). I'm curious why syslog writing is so much more
intense? It seems to me on a really busy syslog server that you
could seriously smoke your HDs with all the writing it's doing. Am I
missing something?

--
Scott Baker - Canby Telcom
RHCE - System Administrator - 503.266.8253
Syslog logging taking too much disk write? [ In reply to ]
Could you post your rsyslog.conf please. Without seeing it, it sounds
like you sync the disc with every write. Unfortunately, this is the
legacy default. You can turn it off with placing a dash before the
selector line:

e.g. *.* /var/log/whatever

syncs after each write, while

*.* -/var/log/whatever

uses buffering - which should be fairly safe with decent hardware and a
UPS...

Rainer

> -----Original Message-----
> From: rsyslog-bounces at lists.adiscon.com [mailto:rsyslog-
> bounces at lists.adiscon.com] On Behalf Of Scott Baker
> Sent: Thursday, December 20, 2007 6:05 PM
> To: rsyslog at lists.adiscon.com
> Subject: [rsyslog] Syslog logging taking too much disk write?
>
> I have a semi busy syslog server which logs about 40 or 50 lines per
> second. I noticed using dstat that it's taking a TON of disk write.
> In the megaBYTES per second range. This seems extremely high to me
> so I wrote a script to test it.
>
> http://www.perturb.org/code/log_lines.pl
>
> First download dstat, gkrellm, or iostat and look at what your
> normal disk write is per second. On my underused desktop it hovers
> around zero or maybe 25KB/s per second.
>
> If I run my script and tell it to log 10 lines to syslog per second
>
> perl log_lines.pl 10
>
> the write usage spikes up to ~160KB/s. We're only writing about 740
> bytes of data per second so why is the disk write so high?
>
> If I tell my script to instead log to a local file in /tmp at 10
> lines per second
>
> perl log_lines.pl 10 -t
>
> The write usage spikes to ~120KB/s about once every 5 seconds (as
> the buffer fills up). I'm curious why syslog writing is so much more
> intense? It seems to me on a really busy syslog server that you
> could seriously smoke your HDs with all the writing it's doing. Am I
> missing something?
>
> --
> Scott Baker - Canby Telcom
> RHCE - System Administrator - 503.266.8253
> _______________________________________________
> rsyslog mailing list
> http://lists.adiscon.net/mailman/listinfo/rsyslog
Syslog logging taking too much disk write? [ In reply to ]
Rainer Gerhards wrote:
> Could you post your rsyslog.conf please. Without seeing it, it sounds
> like you sync the disc with every write. Unfortunately, this is the
> legacy default. You can turn it off with placing a dash before the
> selector line:
>
> e.g. *.* /var/log/whatever
>
> syncs after each write, while
>
> *.* -/var/log/whatever
>
> uses buffering - which should be fairly safe with decent hardware and a
> UPS...

I was using the stock Fedora 8 config which does indeed sync every
write to disk. I put a - in front of all the options and my disk
usage has gone way down!

What sort of buffer does rsyslog use? How often does that buffer
fill up and write to disk? I only ask because sometimes we tail
logfiles in real time to watch things like DHCP etc as they happen.

If the log is 30 seconds behind that may cause a problem.

--
Scott Baker - Canby Telcom
RHCE - System Administrator - 503.266.8253
Syslog logging taking too much disk write? [ In reply to ]
Hi Scott,

[snip]

> What sort of buffer does rsyslog use? How often does that buffer
> fill up and write to disk? I only ask because sometimes we tail
> logfiles in real time to watch things like DHCP etc as they happen.
>
> If the log is 30 seconds behind that may cause a problem.

I suggest you first have a look at:

http://rgerhards.blogspot.com/2007/08/why-is-rsyslog-multi-threaded-and-
is-it.html

The bottom line with the current release is that there is no specific
"output file buffer" - rsyslog writes to the OS and it buffers. Works
pretty well for rapidly incoming traffic. What we do, however, is have a
buffer between messages received and processed. This is primarily meant
for taking care of either a) message bursts or b) temporarily slow
outputs (e.g., initial database connection). If you don't like that
buffer, you can limit it via rsyslog.conf (the default is 10,000
messages max).

With rsyslog v3, there will be a more complex threading scheme and also
some more buffers. I can also envision it will support buffered writes,
enhancing the IO throughput for files (e.g. write in 64K chunks or every
n (milli)seconds, whatever comes first). I am currently in the early
stages of v3, but it will be a very exciting release. And I of course
appreciate feedback from demanding environments (hint, hint ;)).

But v3 will never hold messages longer than a) absolutely necessary or
b) configured by operator. There is a good post on v3 right on the main
page of my blog.

I hope that clarifies, if not, please let me know.

Rainer