While you were doing that I just dumped 200,000 UDP packets from two different sources (100,000 from each) onto my syslog server. I ended up with about 2700 lines of syslog in the file. Some of them were corrupt (multiple messages truncated together). I doubt I have much to add to what you already concluded, though. :) On Tue, Jan 29, 2002 at 05:26:00PM -0500, Marcus J. Ranum wrote: > I'm doing some roughies on an OpenBSD box right now to see how long > syslogging a million records takes, and whether there are any overruns > or dropouts... Right now it appears to be eating a lot of system time - from > looking at it, I'm guessing nobody's ever put syslogd against gprof to see > where it spends its time.... > > Hmmm... Some initial results: on an OpenBSD machine with 800Mhz CPU > and a bunch of memory syslogging one million records in a while loop > using the default UNIX domain socket results in a log file containing > 468677 records - 46% or close to 1/2 the number sent. Drop-outs occurred > pretty much immediately: > Jan 29 16:03:19 hussar hammer[17461]: 138 > Jan 29 16:03:19 hussar hammer[17461]: 139 > Jan 29 16:03:19 hussar hammer[17461]: 1896 > Jan 29 16:03:19 hussar hammer[17461]: 1897 > > 140 records into the session I lost 1700 or so messages. Perhaps this is > some kind of undocumented "compression" technique? ;-) > > The client side was also a software piggie: > 98.55s real 25.03s user 24.08s system > > Ok, I gproffed syslogd just for the hell of it... > % cumulative self self total > time seconds seconds calls ms/call ms/call name > 15.0 5.50 5.50 __thread_sys_open [1] > 12.3 10.03 4.52 __thread_sys_select [5] > 12.2 14.51 4.48 _writev [6] > 10.7 18.43 3.93 _memcpy [7] > 10.6 22.33 3.89 _read [8] > 6.2 24.62 2.29 mcount (67) > > Looks like weirdness hidden in writev; I'm not going to dig > any further. Looks like a lot of my expensive CPU cycles are > going to waste, though.. ;) > > My client took 98 seconds to send a million records, which is to say > 10,000+ records/second. So we know that syslog (on my box, with > my O/S) can't handle 10,000+ records/second. On the client, the > usage profile looks a lot more sane: > % cumulative self self total > time seconds seconds calls ms/call ms/call name > 16.0 8.85 8.85 _sendto [8] > 15.4 17.39 8.54 27419012 0.00 0.00 ___qdivrem [9] > > I whipped a UDP syslog client that sends to localhost over the > syslog port, which meant I had to fire up "syslogd -u" - and repeated > my million record test. The results there were much more interesting! > It used a lot less CPU time and completed quite quickly. :) Of course > the messages file only contained 4604 messages - that is .4% > presumably some output queue was getting overrun and messages > were silently discarded - my sendto(...) code never returned an error, > by the way... > > Conclusions: > syslogd is decidedly not OK for loads in the 10,000 messages/second range on > my machine > > mjr. > --- > Marcus J. Ranum Chief Technology Officer, NFR Security, Inc. > Work: http://www.nfr.com > Personal: http://www.ranum.com -- William Colburn, "Sysprog" <wcolburnat_private> Computer Center, New Mexico Institute of Mining and Technology http://www.nmt.edu/tcc/ http://www.nmt.edu/~wcolburn --------------------------------------------------------------------- To unsubscribe, e-mail: loganalysis-unsubscribeat_private For additional commands, e-mail: loganalysis-helpat_private
This archive was generated by hypermail 2b30 : Tue Jan 29 2002 - 14:41:58 PST