[Bug 217] New: Poor single thraded performance reading from a pip
https://bugzilla.balabit.com/show_bug.cgi?id=217 Summary: Poor single thraded performance reading from a pip Product: syslog-ng Version: 3.4.x Platform: PC OS/Version: Linux Status: NEW Severity: normal Priority: unspecified Component: syslog-ng AssignedTo: bazsi@balabit.hu ReportedBy: erempel@uvic.ca Type of the Report: --- Estimated Hours: 0.0 syslog-ng 3.4.0rc2 ./configure --prefix=%{_prefix} --libdir=%{_libdir} --with-module-dir=%{_libdir}/syslog-ng --mandir=%{_mandir} --infodir=%{_prefix}/share/info \ --sysconfdir=%{_sysconfdir}/syslog-ng --localstatedir=/var/lib/syslog-ng \ --enable-pcre PKG_CONFIG_PATH=%{_libdir}/pkgconfig:%{_prefix}/share/pkgconfig \ --disable-tcp-wrapper Using the attached config file on a Linux Redhat Server 6.3 I can only get approx 2,000 messages per second cat ~/some.log >> /var/log/syslog.pipes/test Using the same config file (with @version 3.3) using 3.3.7 I can process 50,000+ messages per second. By enabling threaded(yes) I can get 50,000+ messages per second. -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=217 --- Comment #1 from Evan Rempel <erempel@uvic.ca> 2013-01-22 01:22:29 --- OK, I think I know what is happening. I am running my test instance in a VMWare host and the disk IO is poor. Because there is a type of flow-control in place due to the multi-threaded options even when not enabled, if there is a destination to disk of the incomming data stream, the source is not read until the output can be flushed. This made all of my tests dependent on the disk IO. By removing all disk destinations, things ran much faster. I'll need to test a little more, but I would wait for my test before "debuging" this. -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=217 --- Comment #2 from Evan Rempel <erempel@uvic.ca> 2013-01-22 07:00:04 --- The best I can tell is that there is something wrong with the file destination in 3.4 Using a file destination seems to block everything. I can't get stats via /usr/local/sbin/syslog-ng-ctl stats --control=/var/local/syslog-ng.ctl because it just hangs. It seems like it does not honour the flush_lines option, or if it does, it fsyncs every line or something. The wait I/O goes to 40% on what is otherwise an idle box. Even though I use a large (2,000,000) log_fifo_size destination d_archive { file("/var/syslog/syslog.test.log" owner("root") group("syslogs") perm(0640) log_fifo_size(2000000) template(t_standardfile)); }; And have source unix_network_tcp { tcp(localip(catamount.comp.uvic.ca) port(514) max_connections(10) log_fetch_limit(500) log_iw_size(1000000) ); }; The destination will not queue up messages more than about 1000. After 3 minutes of elapsed time, the first stats came back with dst.file;d_archive#0;/var/syslog/syslog.test.log;a;dropped;0 dst.file;d_archive#0;/var/syslog/syslog.test.log;a;processed;6000 dst.file;d_archive#0;/var/syslog/syslog.test.log;a;stored;500 If I use a destination of destination d_cat { program("/bin/cat >> /var/syslog/syslog.test.log" log_fifo_size(2000000) template(t_standardfile)); }; Then the messages are processed quickly and the CPU hits 100% for the syslog-ng process. I also see the queued count reach 5,000 at times with this destination. -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=217 --- Comment #3 from Evan Rempel <erempel@uvic.ca> 2013-01-22 07:06:46 --- Created an attachment (id=70) --> (https://bugzilla.balabit.com/attachment.cgi?id=70) minimal config to show the problems. -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=217 Gergely Nagy <algernon@balabit.hu> changed: What |Removed |Added ---------------------------------------------------------------------------- Target Milestone|--- |3.4.1 CC| |algernon@balabit.hu AssignedTo|bazsi@balabit.hu |algernon@balabit.hu -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=217 Gergely Nagy <algernon@balabit.hu> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|NEW |ASSIGNED -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=217 --- Comment #4 from Gergely Nagy <algernon@balabit.hu> 2013-01-22 13:12:00 --- Reproduced, both the insanely slow file destination, and that it starves pretty much everything else. I'm running it under cachegrind, and even ^C is awkwardly slow, let alone reacting to syslog-ng-ctl. -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=217 --- Comment #5 from Gergely Nagy <algernon@balabit.hu> 2013-01-22 13:21:25 --- Looks like its fsync()-ing after each line, and THAT is terribly slow. -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=217 Gergely Nagy <algernon@balabit.hu> changed: What |Removed |Added ---------------------------------------------------------------------------- Resolution| |FIXED Status|ASSIGNED |RESOLVED --- Comment #6 from Gergely Nagy <algernon@balabit.hu> 2013-01-22 13:45:26 --- Right, this is terribly embarassing. Back in May, when restoring fsync(yes) functionality, the order of arguments to one function was mixed up, so that flush-lines was set as if it was fsync, and the value of fsync was set as flush-lines. This resulted in fsync() being permanently enabled, and flush-lines() always being 0 or 1, and this led to horrible performance. Back then, this passed my tests, as I only tested that fsync() gets called, and it did. Lesson learned, I need to do negative tests too. Nevertheless, I corrected this mistake on 3.4's master: https://github.com/balabit/syslog-ng-3.4/commit/c5775b689720c811905ebf55ee07... -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=217 --- Comment #7 from Evan Rempel <erempel@uvic.ca> 2013-01-22 17:56:00 --- Thank you, thank you, thank you. This patch restores performance to what I would expect. -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
participants (1)
-
bugzilla@bugzilla.balabit.com