UDP packet loss with syslog-ng
Hello all, I'm deploying syslog-ng 3.0.8 on a quad-core 2.4Ghz system with 4GB of memory. Using stock kernel settings (e.g., without adjusting net.core.rmem_default), we're not able to handle much more than 100 messages/second (generated from a remote host using the "loggen" tool). At 500 msg/sec (-r 500), we see about 50% loss, and at 1000 msg/sec, we see closer to 60% packet loss. Our configuration looks approximately like this (template definitions elided for brevity): options { time_reap(30); mark_freq(10); keep_hostname(yes); use_fqdn(yes); dns_cache(2000); dns_cache_expire(86400); }; source s_network { udp(); tcp(port(514)); }; destination d_syslog { file("/srv/syslog/bydate/$YEAR-$MONTH-$DAY/messages" template(t_daily_log) create_dirs(yes) ); file("/srv/syslog/byhost/$FULLHOST_FROM/$YEAR-$MONTH-$DAY" template(t_host_log) create_dirs(yes) ); }; log { source(s_network); destination(d_syslog); }; I didn't think these message rates were terribly high, so I was surprised at the loss. We've confirmed that the loss is entirely between the kernel and the application -- using wireshark, we've verified that all of the packets are arriving at the host, and using this: awk '{print}' /inet/udp/514/0/0 > out Our packet loss is < 1%. If I raise the rmem settings like this: net.core.rmem_default = 512000 net.core.rmem_max = 1024000 Then it looks like I can support messages rates around 1000 msgs/sec. If I try with 2000 msgs/sec, the loss rates jumps up again (to around 30%). Do these numbers make sense? This is an unloaded server. The only log traffic hitting this system is from my loggen runs. The filesystem is ext3 on top of a hardware RAID5 array. I've tried fiddling with some of the syslog-ng global options (e.g., flush_lines(), log_fetch_limit()), but without having much impact on performance. I would appreciate any help you can send our way. Thanks! -- Lars
Hi Lars, try increasing your UDP receive buffers as outlined here: http://nms.gdd.net/index.php/Install_Guide_for_LogZilla_v3.0#UDP_Buffers <http://nms.gdd.net/index.php/Install_Guide_for_LogZilla_v3.0#UDP_Buffers> ______________________________________________________________ Clayton Dukes ______________________________________________________________ On Fri, Oct 15, 2010 at 4:39 PM, Lars Kellogg-Stedman <lars@oddbit.com>wrote:
Hello all,
I'm deploying syslog-ng 3.0.8 on a quad-core 2.4Ghz system with 4GB of memory. Using stock kernel settings (e.g., without adjusting net.core.rmem_default), we're not able to handle much more than 100 messages/second (generated from a remote host using the "loggen" tool). At 500 msg/sec (-r 500), we see about 50% loss, and at 1000 msg/sec, we see closer to 60% packet loss.
Our configuration looks approximately like this (template definitions elided for brevity):
options { time_reap(30); mark_freq(10); keep_hostname(yes); use_fqdn(yes); dns_cache(2000); dns_cache_expire(86400); };
source s_network { udp(); tcp(port(514)); };
destination d_syslog { file("/srv/syslog/bydate/$YEAR-$MONTH-$DAY/messages" template(t_daily_log) create_dirs(yes) ); file("/srv/syslog/byhost/$FULLHOST_FROM/$YEAR-$MONTH-$DAY" template(t_host_log) create_dirs(yes) ); };
log { source(s_network); destination(d_syslog); };
I didn't think these message rates were terribly high, so I was surprised at the loss. We've confirmed that the loss is entirely between the kernel and the application -- using wireshark, we've verified that all of the packets are arriving at the host, and using this:
awk '{print}' /inet/udp/514/0/0 > out
Our packet loss is < 1%.
If I raise the rmem settings like this:
net.core.rmem_default = 512000 net.core.rmem_max = 1024000
Then it looks like I can support messages rates around 1000 msgs/sec. If I try with 2000 msgs/sec, the loss rates jumps up again (to around 30%).
Do these numbers make sense? This is an unloaded server. The only log traffic hitting this system is from my loggen runs. The filesystem is ext3 on top of a hardware RAID5 array. I've tried fiddling with some of the syslog-ng global options (e.g., flush_lines(), log_fetch_limit()), but without having much impact on performance.
I would appreciate any help you can send our way. Thanks!
-- Lars
______________________________________________________________________________ Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng FAQ: http://www.campin.net/syslog-ng/faq.html
Hi Lars, try increasing your UDP receive buffers as outlined here: http://nms.gdd.net/index.php/Install_Guide_for_LogZilla_v3.0#UDP_Buffers
As I said in my message, this is something I've already done. It did have a salutary effect, but I had additional questions.
On Fri, Oct 15, 2010 at 04:55:33PM -0400, Lars Kellogg-Stedman wrote:
Hi Lars, try increasing your UDP receive buffers as outlined here: http://nms.gdd.net/index.php/Install_Guide_for_LogZilla_v3.0#UDP_Buffers
As I said in my message, this is something I've already done. It did have a salutary effect, but I had additional questions.
Actually, you did not say it in your message. Because searching it for the string 'buf' returns no results. So in fact we actually are reading your mails after all. :-) Matthew.
Actually, you did not say it in your message. Because searching it for the string 'buf' returns no results.
Look, I'm not trying to be difficult, but I do at least expect people to read my email before responding. Here, I'll quote it for you: If I raise the rmem settings like this: net.core.rmem_default = 512000 net.core.rmem_max = 1024000 Then it looks like I can support messages rates around 1000 msgs/sec. If I try with 2000 msgs/sec, the loss rates jumps up again (to around 30%). I'm sorry if you got bored before reading it. I was trying to provide sufficient details that people wouldn't suggest the things I've already tried. Additionally, as far as I can tell, setting net.core.rmem_default is largely equivalent, from the point of view of syslog-ng, to setting so_rcvbuf() (since it sets the default receive buffer size). On a system with lots of open sockets, setting a lower net.core.rmem_default and using so_rcvbuf() would probably make more sense.
On Fri, Oct 15, 2010 at 05:11:21PM -0400, Lars Kellogg-Stedman wrote:
Actually, you did not say it in your message. Because searching it for the string 'buf' returns no results.
Look, I'm not trying to be difficult, but I do at least expect people to read my email before responding. Here, I'll quote it for you:
I was reading your email but I'm not seeing much reason to continue if this is the kind of things it will contain. I'm sorry your setup is having problems and I'm sure you are frustrated about it but that doesn't necessitate flames. None of these options you tried were 100% the same as the set we have suggested adjusting. So my point still stands that we did read your mail and suggest new ideas.
I'm sorry if you got bored before reading it. I was trying to provide sufficient details that people wouldn't suggest the things I've already tried.
I did read the entire thing before replying as I do with every mail I've received in my long career.
Additionally, as far as I can tell, setting net.core.rmem_default is largely equivalent, from the point of view of syslog-ng, to setting so_rcvbuf() (since it sets the default receive buffer size). On a system with lots of open sockets, setting a lower net.core.rmem_default and using so_rcvbuf() would probably make more sense.
Could be. But unless you are willing to invest the time to read the libc sources and the kernel sources and man 7 socket and other documentation to confirm, it's worth trying the setting to see if it helps since it's helped me with these sorts of issues in the past. Matthew.
I was reading your email but I'm not seeing much reason to continue if this is the kind of things it will contain.
And I support your right to ignore my email. Moving on... -- Lars
Hi Lars, I'm sorry if my response didn't help you, however, I have been through exactly what you are describing and it is outlined in that link I sent. Please check the "update" part of the wiki that quotes what Baszi told me and why I ended up using the recvbuf in syslog-ng. Setting it there made everything work for me. ______________________________________________________________ Clayton Dukes ______________________________________________________________ On Fri, Oct 15, 2010 at 5:11 PM, Lars Kellogg-Stedman <lars@oddbit.com>wrote:
Actually, you did not say it in your message. Because searching it for the string 'buf' returns no results.
Look, I'm not trying to be difficult, but I do at least expect people to read my email before responding. Here, I'll quote it for you:
If I raise the rmem settings like this:
net.core.rmem_default = 512000 net.core.rmem_max = 1024000
Then it looks like I can support messages rates around 1000 msgs/sec. If I try with 2000 msgs/sec, the loss rates jumps up again (to around 30%).
I'm sorry if you got bored before reading it. I was trying to provide sufficient details that people wouldn't suggest the things I've already tried.
Additionally, as far as I can tell, setting net.core.rmem_default is largely equivalent, from the point of view of syslog-ng, to setting so_rcvbuf() (since it sets the default receive buffer size). On a system with lots of open sockets, setting a lower net.core.rmem_default and using so_rcvbuf() would probably make more sense.
______________________________________________________________________________ Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng FAQ: http://www.campin.net/syslog-ng/faq.html
I'm getting upwards of 15k mps no problem on older hardware with rmem default/max = 124928/131071, so your numbers sound pretty off. One thing to do would be to make sure syslog-ng isn't blocking on DNS all the time. A great sanity check is to use nc -l 514 -u > /some/out/file to prove that your kernel settings can keep up. Send a bunch of packets with loggen, then do a wc -l /some/out/file to check how many were received. If that's looking good, I recommend running tcpdump/wireshark to find the rate of DNS lookups from the box. If the cache is working, there should hardly be any after a minute or two. A full answer would require seeing the values of your output templates. On Fri, Oct 15, 2010 at 3:39 PM, Lars Kellogg-Stedman <lars@oddbit.com> wrote:
Hello all,
I'm deploying syslog-ng 3.0.8 on a quad-core 2.4Ghz system with 4GB of memory. Using stock kernel settings (e.g., without adjusting net.core.rmem_default), we're not able to handle much more than 100 messages/second (generated from a remote host using the "loggen" tool). At 500 msg/sec (-r 500), we see about 50% loss, and at 1000 msg/sec, we see closer to 60% packet loss.
Our configuration looks approximately like this (template definitions elided for brevity):
options { time_reap(30); mark_freq(10); keep_hostname(yes); use_fqdn(yes); dns_cache(2000); dns_cache_expire(86400); };
source s_network { udp(); tcp(port(514)); };
destination d_syslog { file("/srv/syslog/bydate/$YEAR-$MONTH-$DAY/messages" template(t_daily_log) create_dirs(yes) ); file("/srv/syslog/byhost/$FULLHOST_FROM/$YEAR-$MONTH-$DAY" template(t_host_log) create_dirs(yes) ); };
log { source(s_network); destination(d_syslog); };
I didn't think these message rates were terribly high, so I was surprised at the loss. We've confirmed that the loss is entirely between the kernel and the application -- using wireshark, we've verified that all of the packets are arriving at the host, and using this:
awk '{print}' /inet/udp/514/0/0 > out
Our packet loss is < 1%.
If I raise the rmem settings like this:
net.core.rmem_default = 512000 net.core.rmem_max = 1024000
Then it looks like I can support messages rates around 1000 msgs/sec. If I try with 2000 msgs/sec, the loss rates jumps up again (to around 30%).
Do these numbers make sense? This is an unloaded server. The only log traffic hitting this system is from my loggen runs. The filesystem is ext3 on top of a hardware RAID5 array. I've tried fiddling with some of the syslog-ng global options (e.g., flush_lines(), log_fetch_limit()), but without having much impact on performance.
I would appreciate any help you can send our way. Thanks!
-- Lars ______________________________________________________________________________ Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng FAQ: http://www.campin.net/syslog-ng/faq.html
the time. A great sanity check is to use nc -l 514 -u > /some/out/file
Right, I did that...as I described in the message.
how many were received. If that's looking good, I recommend running tcpdump/wireshark to find the rate of DNS lookups from the box.
I'll take a look. I'm coming from a single host, and I do have dns caching enabled, so I would be surprised if this is the problem. As a first step I may just disable DNS and see if that has any impact on the problem.
two. A full answer would require seeing the values of your output templates.
template t_daily_log { template("$FULLHOST_FROM $YEAR-$MONTH-$DAY $HOUR:$MIN:$SEC [$FACILITY:$LEVEL] [$PROGRAM:$PID] $MSG\n"); }; template t_host_log { template("$YEAR-$MONTH-$DAY $HOUR:$MIN:$SEC [$FACILITY:$LEVEL] [$PROGRAM:$PID] $MSG\n"); };
Actually, I missed what you were doing with awk because I don't think I've ever seen /inet before. Are you on FreeBSD? My experience (and cited performance numbers) is all on Linux. My suspicion is that nc would take into account more things like SO_RCVBUF, so I'd be interested to see if there's any difference between redirecting the raw socket and running netcat. Your template refers to DNS hostnames, so it's certainly possible that it's a factor, though I agree that a single hostname with caching enabled should really not be a problem. On Fri, Oct 15, 2010 at 3:54 PM, Lars Kellogg-Stedman <lars@oddbit.com> wrote:
the time. A great sanity check is to use nc -l 514 -u > /some/out/file
Right, I did that...as I described in the message.
how many were received. If that's looking good, I recommend running tcpdump/wireshark to find the rate of DNS lookups from the box.
I'll take a look. I'm coming from a single host, and I do have dns caching enabled, so I would be surprised if this is the problem. As a first step I may just disable DNS and see if that has any impact on the problem.
two. A full answer would require seeing the values of your output templates.
template t_daily_log { template("$FULLHOST_FROM $YEAR-$MONTH-$DAY $HOUR:$MIN:$SEC [$FACILITY:$LEVEL] [$PROGRAM:$PID] $MSG\n"); };
template t_host_log { template("$YEAR-$MONTH-$DAY $HOUR:$MIN:$SEC [$FACILITY:$LEVEL] [$PROGRAM:$PID] $MSG\n"); }; ______________________________________________________________________________ Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng FAQ: http://www.campin.net/syslog-ng/faq.html
Actually, I missed what you were doing with awk because I don't think I've ever seen /inet before. Are you on FreeBSD? My experience (and cited performance numbers) is all on Linux.
Me too. Awk has supported network connectivity for a decade or so, I think (since v3.1). Using netcat, the results are pretty much the same. At 2000 msgs/sec I get around 10% loss, which is a lot better than syslog-ng. One of the possibilities I'm looking at is putting something like netcat (or socklog, http://smarden.org/socklog/) in front of syslog-ng and spooling the messages from the network directly to disk, and then post-processing them with syslog-ng. This would solve the performance problem, since these simpler tools appear to have no problem supporting higher logging rates, and we've got disk space to spare. Injecting the messages into syslog-ng in a useful fashion might be a bit of a challenge. Our alternate plan is just to use tcp syslog across the board (which avoids the loss problem), although I'm concerned that this may impact the connection-tracking firewalls in use around our environment.
Ah, so it's not a real file, it's part of awk. That explains it. Ok, maybe even easier than running tcpdump for DNS would be to just swap $FULLHOST_FROM with $SOURCEIP and see if that improves things. Two more things to look at: what is the CPU % when it's running, and if you strace it what syscalls does it seem to be doing the most? Gettimeofday should be in there quite a bit, but sometimes calls you didn't expect jump out and show what's blocking. You really shouldn't have to post-process with syslog-ng; there's got to be something wrong. I also find your raw socket numbers to be lower than I'd expect. I would expect 0 loss through 10k mps at least. On Fri, Oct 15, 2010 at 4:22 PM, Lars Kellogg-Stedman <lars@oddbit.com> wrote:
Actually, I missed what you were doing with awk because I don't think I've ever seen /inet before. Are you on FreeBSD? My experience (and cited performance numbers) is all on Linux.
Me too. Awk has supported network connectivity for a decade or so, I think (since v3.1). Using netcat, the results are pretty much the same. At 2000 msgs/sec I get around 10% loss, which is a lot better than syslog-ng.
One of the possibilities I'm looking at is putting something like netcat (or socklog, http://smarden.org/socklog/) in front of syslog-ng and spooling the messages from the network directly to disk, and then post-processing them with syslog-ng. This would solve the performance problem, since these simpler tools appear to have no problem supporting higher logging rates, and we've got disk space to spare. Injecting the messages into syslog-ng in a useful fashion might be a bit of a challenge.
Our alternate plan is just to use tcp syslog across the board (which avoids the loss problem), although I'm concerned that this may impact the connection-tracking firewalls in use around our environment. ______________________________________________________________________________ Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng FAQ: http://www.campin.net/syslog-ng/faq.html
Ok, maybe even easier than running tcpdump for DNS would be to just swap $FULLHOST_FROM with $SOURCEIP and see if that improves things.
That didn't seem to impact the rate at all.
Two more things to look at: what is the CPU % when it's running, and
Running with 2000 messages/second, the CPU is usually at least 98% idle. The CPU display from top looks approximately like the following throughout the duration of the test: Cpu(s): 1.1%us, 0.3%sy, 0.0%ni, 98.5%id, 0.0%wa, 0.0%hi, 0.1%si, 0.0%st So there's not much waiting for i/o, either.
if you strace it what syscalls does it seem to be doing the most? Gettimeofday should be in there quite a bit, but sometimes calls you didn't expect jump out and show what's blocking.
Running 'strace -c' against the syslog-ng process yields: % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 47.43 0.008792 0 42984 write 28.85 0.005347 2 2535 poll 12.56 0.002328 0 42984 lseek 11.16 0.002068 0 21975 484 recvfrom 0.00 0.000000 0 1 close 0.00 0.000000 0 11 stat ------ ----------- ----------- --------- --------- ---------------- 100.00 0.018535 110490 484 total The errors are all from recvfrom() reporting EAGAIN. I don't think anything here is terribly surprising.
You really shouldn't have to post-process with syslog-ng; there's got to be something wrong. I also find your raw socket numbers to be lower than I'd expect.
Me too! :) Things are better (but still not perfect) with a 2GB buffer, but we're only throwing a 4Mbps stream of data at the system, and I would expect it to handle this without a problem. I remain puzzled.
Me too! :) Things are better (but still not perfect) with a 2GB
*2MB. And as long as we're talking about buffers:
A little. It wasn't clear from the documentation how so_rcvbuf() interacts with the kernel settings (net.core.rmem_default and net.core.rmem_max).
It seems like other folks on the list weren't clear on this, either, so I went ahead and did a little research. If you take a look in net/core/sock.c in the Linux kernel, you'll see that: - If you don't explicitly set a receive buffer size via setsockopt(), the kernel uses the value of the net.core.rmem_default sysctl to set the size of sk->sk_rcvbuf: sk->sk_rcvbuf = sysctl_rmem_default; - Calling setsockopt() with SO_RCVBUF sets sk->sk_rcvbuf. In most cases, the actual value of sk->sk_rcvbuf is double what you asked for when you called SO_RCVBUF: if ((val * 2) < SOCK_MIN_RCVBUF) sk->sk_rcvbuf = SOCK_MIN_RCVBUF; else sk->sk_rcvbuf = val * 2; break; So it looks as if calling setsockopt() with the same value as rmem_default will in fact give you roughly twice the buffer space.
On Fri, 2010-10-15 at 16:07 -0500, Martin Holste wrote:
Actually, I missed what you were doing with awk because I don't think I've ever seen /inet before. Are you on FreeBSD? My experience (and cited performance numbers) is all on Linux. My suspicion is that nc would take into account more things like SO_RCVBUF, so I'd be interested to see if there's any difference between redirecting the raw socket and running netcat.
Your template refers to DNS hostnames, so it's certainly possible that it's a factor, though I agree that a single hostname with caching enabled should really not be a problem.
DNS resolution happens only once when a message is received. Even if you used it 20 times in your template, DNS resolution only happens once. -- Bazsi
My concern was just to rule out it wasn't happening once per message. On Sat, Oct 16, 2010 at 12:02 AM, Balazs Scheidler <bazsi@balabit.hu> wrote:
On Fri, 2010-10-15 at 16:07 -0500, Martin Holste wrote:
Actually, I missed what you were doing with awk because I don't think I've ever seen /inet before. Are you on FreeBSD? My experience (and cited performance numbers) is all on Linux. My suspicion is that nc would take into account more things like SO_RCVBUF, so I'd be interested to see if there's any difference between redirecting the raw socket and running netcat.
Your template refers to DNS hostnames, so it's certainly possible that it's a factor, though I agree that a single hostname with caching enabled should really not be a problem.
DNS resolution happens only once when a message is received. Even if you used it 20 times in your template, DNS resolution only happens once.
-- Bazsi
______________________________________________________________________________ Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng FAQ: http://www.campin.net/syslog-ng/faq.html
Hello Lars, In my own experience coding UDP applications I could handle upwards of 3000 messages per second. However I was not trying to output them to a file. What network adapter and Ethernet driver does the machine use? Which operating system? Could you try a different operating system as a process of elimination (maybe switch between Linux, BSD, and Solaris)? Did you try tweaking: log_fetch_limit() so_rcvbuf() so_sndbuf() http://www.balabit.com/sites/default/files/documents/syslog-ng-ose-v3.1-guid... I have noticed in my own code that SO_RCVBUF makes a HUGE difference. Do you know for sure that when 'loggen' says it's creating X msgs/sec, that this reading is actually accurate? Can you profile syslog-ng using oprofile or the various built in profiling and debugging options in its configure script? Can you check if the CFLAGS look good? -O2 and -Os are usually the best, for me -O3 seems to slow things down. Also check the arch and tune settings. Consider trying it with the Intel C Compiler to see if this helps. Let's try to get some more details about your platform and identify the bottlenecks so we can get to the details quickly and avoid guessing too much. Matthew. On Fri, Oct 15, 2010 at 04:39:54PM -0400, Lars Kellogg-Stedman wrote:
Hello all,
I'm deploying syslog-ng 3.0.8 on a quad-core 2.4Ghz system with 4GB of memory. Using stock kernel settings (e.g., without adjusting net.core.rmem_default), we're not able to handle much more than 100 messages/second (generated from a remote host using the "loggen" tool). At 500 msg/sec (-r 500), we see about 50% loss, and at 1000 msg/sec, we see closer to 60% packet loss.
Our configuration looks approximately like this (template definitions elided for brevity):
options { time_reap(30); mark_freq(10); keep_hostname(yes); use_fqdn(yes); dns_cache(2000); dns_cache_expire(86400); };
source s_network { udp(); tcp(port(514)); };
destination d_syslog { file("/srv/syslog/bydate/$YEAR-$MONTH-$DAY/messages" template(t_daily_log) create_dirs(yes) ); file("/srv/syslog/byhost/$FULLHOST_FROM/$YEAR-$MONTH-$DAY" template(t_host_log) create_dirs(yes) ); };
log { source(s_network); destination(d_syslog); };
I didn't think these message rates were terribly high, so I was surprised at the loss. We've confirmed that the loss is entirely between the kernel and the application -- using wireshark, we've verified that all of the packets are arriving at the host, and using this:
awk '{print}' /inet/udp/514/0/0 > out
Our packet loss is < 1%.
If I raise the rmem settings like this:
net.core.rmem_default = 512000 net.core.rmem_max = 1024000
Then it looks like I can support messages rates around 1000 msgs/sec. If I try with 2000 msgs/sec, the loss rates jumps up again (to around 30%).
Do these numbers make sense? This is an unloaded server. The only log traffic hitting this system is from my loggen runs. The filesystem is ext3 on top of a hardware RAID5 array. I've tried fiddling with some of the syslog-ng global options (e.g., flush_lines(), log_fetch_limit()), but without having much impact on performance.
I would appreciate any help you can send our way. Thanks!
-- Lars ______________________________________________________________________________ Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng FAQ: http://www.campin.net/syslog-ng/faq.html
file. What network adapter and Ethernet driver does the machine use?
This is a Dell R610, which reports: Ethernet controller: Broadcom Corporation NetXtreme II BCM5709 Gigabit Ethernet The kernel is using the "bnx2" driver. There doesn't appear to be a problem getting packets from the network to a user space program like awk or netcat.
Which operating system?
Linux (CentOS 5.5).
Did you try tweaking:
log_fetch_limit() so_rcvbuf() so_sndbuf()
A little. It wasn't clear from the documentation how so_rcvbuf() interacts with the kernel settings (net.core.rmem_default and net.core.rmem_max). My naive assumption is that setting so_rcvbuf() is largely the same as setting net.core.rmem_default (but with a more local impact). Trying various values for log_fetch_limit() didn't appear to have much impact on things, but absent some guidance on what would constitute sensible numbers I was sort of flailing around.
Do you know for sure that when 'loggen' says it's creating X msgs/sec, that this reading is actually accurate?
Yes.
Can you profile syslog-ng using oprofile or the various built in profiling and debugging options in its configure script? Can you check if the CFLAGS look good?
I'm using the binary packages from balabit.com. If these aren't optimally built, I'm looking at the wrong product.
On Fri, Oct 15, 2010 at 05:01:27PM -0400, Lars Kellogg-Stedman wrote:
file. What network adapter and Ethernet driver does the machine use?
This is a Dell R610, which reports:
Ethernet controller: Broadcom Corporation NetXtreme II BCM5709 Gigabit Ethernet
The kernel is using the "bnx2" driver. There doesn't appear to be a problem getting packets from the network to a user space program like awk or netcat.
Yeah I understand that they seem to be getting to user space OK. But in past work I have seen different Ethernet adapters which caused stack misbehavior because their drivers were bad. So I wanted to be sure you were not running one of the adapters which had caused problems for me when I used to work on a Linux based firewall appliance.
Which operating system?
Linux (CentOS 5.5).
OK. RHEL 5 is kind of ancient unfortunately. I've seen it cause problems for me before. Is there any possibility to try Ubuntu 10.04 LTS or something else to help narrow down the problem, or do some sort of profiling?
Trying various values for log_fetch_limit() didn't appear to have much impact on things, but absent some guidance on what would constitute sensible numbers I was sort of flailing around.
Fair enough.
Can you profile syslog-ng using oprofile or the various built in profiling and debugging options in its configure script? Can you check if the CFLAGS look good?
I'm using the binary packages from balabit.com. If these aren't optimally built, I'm looking at the wrong product.
Not every build can be optimal for every situation. This is open source. If it doesn't work, then you are going to have to help do some of the troubleshooting, unless you feel like buying a support contract. There are some dedicated people here who want to help but you have to work with us too. Matthew.
On Fri, 2010-10-15 at 16:39 -0400, Lars Kellogg-Stedman wrote:
Hello all,
I'm deploying syslog-ng 3.0.8 on a quad-core 2.4Ghz system with 4GB of memory. Using stock kernel settings (e.g., without adjusting net.core.rmem_default), we're not able to handle much more than 100 messages/second (generated from a remote host using the "loggen" tool). At 500 msg/sec (-r 500), we see about 50% loss, and at 1000 msg/sec, we see closer to 60% packet loss.
Our configuration looks approximately like this (template definitions elided for brevity):
options { time_reap(30); mark_freq(10); keep_hostname(yes); use_fqdn(yes); dns_cache(2000); dns_cache_expire(86400); };
source s_network { udp(); tcp(port(514)); };
destination d_syslog { file("/srv/syslog/bydate/$YEAR-$MONTH-$DAY/messages" template(t_daily_log) create_dirs(yes) ); file("/srv/syslog/byhost/$FULLHOST_FROM/$YEAR-$MONTH-$DAY" template(t_host_log) create_dirs(yes) ); };
log { source(s_network); destination(d_syslog); };
I didn't think these message rates were terribly high, so I was surprised at the loss. We've confirmed that the loss is entirely between the kernel and the application -- using wireshark, we've verified that all of the packets are arriving at the host, and using this:
awk '{print}' /inet/udp/514/0/0 > out
Our packet loss is < 1%.
If I raise the rmem settings like this:
net.core.rmem_default = 512000 net.core.rmem_max = 1024000
Then it looks like I can support messages rates around 1000 msgs/sec. If I try with 2000 msgs/sec, the loss rates jumps up again (to around 30%).
Do these numbers make sense? This is an unloaded server. The only log traffic hitting this system is from my loggen runs. The filesystem is ext3 on top of a hardware RAID5 array. I've tried fiddling with some of the syslog-ng global options (e.g., flush_lines(), log_fetch_limit()), but without having much impact on performance.
I would appreciate any help you can send our way. Thanks!
Hmm. the numbers you are seeing are indeed low, with sufficient buffer sizes I could get up to the 20k message/sec range with syslog-ng, although it's been a while I last tested it. What I'd recommend is to calculate how much _bytes_ the message rate you are generating means. If you generate 2000 messages, 300 byte each (loggen default IIRC), that's 600000 bytes every second. syslog-ng is single threaded, thus the latency to write to the disk applies. This means that it may take some time for syslog-ng to care about its source, if it is busy writing out messages. This is the #1 reason why I want to work on multithreading. With a flow controlled source, syslog-ng is able to do about 70-75k msg/sec. But not with UDP. In order to improve the numbers, I'd: 1) increase the receive buffer rate to 3-5 seconds (e.g. 3-5MB, not just 0.5) 2) increase log_fetch_limit() to a larger value, this controls how much messages syslog-ng fetches in each poll iteration. Increase this to 3-500 3) increase log_fifo_size() for the destination, by taking the fetch_limit values for each sources feeding the destination (so if you have two sources, each with 1000 fetch limit, then the destination queue should be _at least_ 2000, preferably rounded to the next order of magnitude (e.g. with 2x1000 fetch-limits, increase fifo to 10000) You haven't included in your email whether syslog-ng itself is dropping messages, or the kernel. netstat drop counts or syslog-ng statistics should help decide that. -- Bazsi
Hmm. the numbers you are seeing are indeed low, with sufficient buffer sizes I could get up to the 20k message/sec range with syslog-ng...
It's better now, having adjusted the buffer sizes way up. I'd like to recommend a change to the documenation. In section 7: http://www.balabit.com/sites/default/files/documents/syslog-ng-admin-guide_e... The issue of buffer size is addressed like this: "This section provides tips on optimizing the performance of syslog-ng. Optimizing the performance is important for syslog-ng hosts that handle large traffic... When receiving lots of messages using the UDP protocol, increase the size of the UDP receive buffer on the syslog-ng hosts." I would suggest that with the default Linux kernel values for UDP receive buffer size, adjusting the UDP receive buffer size is necessary to get performance above "crappy". That is, this isn't just a necessity for "high volume" sites; it should probably be a recommended practice for anyone planning on accepting UDP syslog messages on a Linux host. Making this more prominent in the documentation might save a lot of people from the rude surprise that comes with the default buffer sizes. Things are running much better now having made these changes. I'm going to write up the performance test I did in a little more detail and stick it online somewhere, hopefully saving someone else a little bit of time in the future.
Glad to hear you got things working, but I don't understand why this isn't an issue on SLES 11 with default buffer sizes (131071 bytes) in which I can get > 15k mps with 0 drops. On Sat, Oct 16, 2010 at 1:10 PM, Lars Kellogg-Stedman <lars@oddbit.com> wrote:
Hmm. the numbers you are seeing are indeed low, with sufficient buffer sizes I could get up to the 20k message/sec range with syslog-ng...
It's better now, having adjusted the buffer sizes way up. I'd like to recommend a change to the documenation. In section 7:
http://www.balabit.com/sites/default/files/documents/syslog-ng-admin-guide_e...
The issue of buffer size is addressed like this:
"This section provides tips on optimizing the performance of syslog-ng. Optimizing the performance is important for syslog-ng hosts that handle large traffic... When receiving lots of messages using the UDP protocol, increase the size of the UDP receive buffer on the syslog-ng hosts."
I would suggest that with the default Linux kernel values for UDP receive buffer size, adjusting the UDP receive buffer size is necessary to get performance above "crappy". That is, this isn't just a necessity for "high volume" sites; it should probably be a recommended practice for anyone planning on accepting UDP syslog messages on a Linux host. Making this more prominent in the documentation might save a lot of people from the rude surprise that comes with the default buffer sizes.
Things are running much better now having made these changes. I'm going to write up the performance test I did in a little more detail and stick it online somewhere, hopefully saving someone else a little bit of time in the future. ______________________________________________________________________________ Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng FAQ: http://www.campin.net/syslog-ng/faq.html
Glad to hear you got things working, but I don't understand why this isn't an issue on SLES 11 with default buffer sizes (131071 bytes) in which I can get > 15k mps with 0 drops.
It's a mystery to me. If anyone else is paying attention to this thread, I'd be curious to here which of us is experiencing the more common case...
This is not at all a surprise to me. I have nothing but problems with RHEL. In this case SLES 11 was released in 2009 and RHEL 5 was released in 2007. Not to mention Redhat applies a lot of idiotic patches to their code. I am guessing the kernel and scheduling behavior are different so a different buffer size is required. Their could also be differences in network adapter polling versus interrupt processing, etc. Without trying it under different situations and running oprofile or systemtap etc. it's hard to say in detail. Matthew. On Sat, Oct 16, 2010 at 03:02:33PM -0500, Martin Holste wrote:
Glad to hear you got things working, but I don't understand why this isn't an issue on SLES 11 with default buffer sizes (131071 bytes) in which I can get > 15k mps with 0 drops.
On Sat, Oct 16, 2010 at 1:10 PM, Lars Kellogg-Stedman <lars@oddbit.com> wrote:
Hmm. the numbers you are seeing are indeed low, with sufficient buffer sizes I could get up to the 20k message/sec range with syslog-ng...
It's better now, having adjusted the buffer sizes way up. I'd like to recommend a change to the documenation. In section 7:
http://www.balabit.com/sites/default/files/documents/syslog-ng-admin-guide_e...
The issue of buffer size is addressed like this:
"This section provides tips on optimizing the performance of syslog-ng. Optimizing the performance is important for syslog-ng hosts that handle large traffic... When receiving lots of messages using the UDP protocol, increase the size of the UDP receive buffer on the syslog-ng hosts."
I would suggest that with the default Linux kernel values for UDP receive buffer size, adjusting the UDP receive buffer size is necessary to get performance above "crappy". That is, this isn't just a necessity for "high volume" sites; it should probably be a recommended practice for anyone planning on accepting UDP syslog messages on a Linux host. Making this more prominent in the documentation might save a lot of people from the rude surprise that comes with the default buffer sizes.
Things are running much better now having made these changes. I'm going to write up the performance test I did in a little more detail and stick it online somewhere, hopefully saving someone else a little bit of time in the future. ______________________________________________________________________________ Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng FAQ: http://www.campin.net/syslog-ng/faq.html
______________________________________________________________________________ Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng FAQ: http://www.campin.net/syslog-ng/faq.html
Hi, I am unable to see/extract Message field from MYSQL however I can see HOST, PRIORITY, DATE and TIME from MYSQL using open syslog_NG Thanks Anis
Thanks for the suggestion. Sending it over to the docs team. ----- Original message -----
Hmm. the numbers you are seeing are indeed low, with sufficient buffer sizes I could get up to the 20k message/sec range with syslog-ng...
It's better now, having adjusted the buffer sizes way up. I'd like to recommend a change to the documenation. In section 7:
http://www.balabit.com/sites/default/files/documents/syslog-ng-admin-guide_e...
The issue of buffer size is addressed like this:
"This section provides tips on optimizing the performance of syslog-ng. Optimizing the performance is important for syslog-ng hosts that handle large traffic... When receiving lots of messages using the UDP protocol, increase the size of the UDP receive buffer on the syslog-ng hosts."
I would suggest that with the default Linux kernel values for UDP receive buffer size, adjusting the UDP receive buffer size is necessary to get performance above "crappy". That is, this isn't just a necessity for "high volume" sites; it should probably be a recommended practice for anyone planning on accepting UDP syslog messages on a Linux host. Making this more prominent in the documentation might save a lot of people from the rude surprise that comes with the default buffer sizes.
Things are running much better now having made these changes. I'm going to write up the performance test I did in a little more detail and stick it online somewhere, hopefully saving someone else a little bit of time in the future.
participants (6)
-
Anisur Rehman(IT)
-
Balazs Scheidler
-
Clayton Dukes
-
Lars Kellogg-Stedman
-
Martin Holste
-
Matthew Hall