[syslog-ng]simple performance test paradigm
Jon Marks
j-marks@uiuc.edu
Thu, 24 May 2001 12:27:58 -0500
--Qxx1br4bt0+wmkIi
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
Hi,
This is in reponse to the request for an alternative logger--
some of this code could probably be adapted for that job without too
much fuss. This stuff is tested on Solaris7/8 and AIX4.3.3, but probably
not too hard to get to work for other platforms. In any case..
In order to performance-test a syslog-ng installation and compare with
vendor syslogd's, I wrote a simple set of three programs. One is the main
log message generator (which uses the syslog.h API to log locally), one
is a "master" synchronization control, and one gathers the results. These
are each little single-sourcefile programs. They're pretty primitive, so
don't expect the greatest in command line processing and user interface,
but could be useful for setting up, testing, and performance profiling.
The main log message generator "syslogtest.c" takes a facility and level,
number of repetitions, a sleep interval, and a "server mode" flag on
the command line. It locally logs the specified number of messages
(like logger, but with with preset content) at the given priority with
a sequence number, sleeping the given number of microseconds between
each. After logging the battery of messages, the running time for the
battery is also logged (and output to the terminal along with PID). In
"server mode" it listens to a preset TCP port for a connection from the
master synchronization control.
The master control "master.c" reads "./servers" for a flat list of
hostnames to connect with. Each host runs an instance of "syslogtest" in
"server mode". Once connected, the user can give a simple "go" signal
or "exit" signal. When the given the "go" signal, each server sends the
volley of syslog messages specified on its command line, forks (just
to change the reported PID), and waits for another signal. When given
"stop" all servers exit. Consider when each host's syslog daemon is
configured to send to a common loghost. This lets you recruit a number
of synchronized remote hosts to either flood syslog-ng (or syslogd) and
measure message loss, or (by using the microsecond sleeping) simulate
the intended server load.
The last program is a perl script, "results," which takes as arguments
a logfile name, a PID, and a number of trials. It reads the logfile,
scanning for lines by the given PID, and tracking the sequence numbers
to determine which are missing, and reports the results. After running
a test trial, this is run at each syslogtest host to determine how
many were lost locally (e.g. in AIX's datagram /dev/log socket), and
then on the common loghost to determine which ones never made it over
the network or were dropped by syslog-ng.
You can use this to help you tune output fifo sizes under particular
loads, or to determine the maximum reasonable capacity of your loghost.
Oh, yeah-- if you invoke the syslogtest.c program as "lasttest" then
it omits the sequence numbers. This generates "last message repeated..."
output from vendor syslogd's (and was used to develop the patch
submitted previously).
--
Jonathan Marks
Systems Administrator, Production Systems Group
Computing and Communication Services Office
University of Illinois at Urbana-Champaign
--Qxx1br4bt0+wmkIi
Content-Type: text/plain; charset=us-ascii
Content-Disposition: attachment; filename="syslogtest.c"
/* syslogtest.c
*
* By Jonathan Marks
* j-marks@uiuc.edu
*
* Compiling:
* Solaris: cc syslogtest.c -o syslogtest -lxnet
* AIX: cc syslogtest.c -o syslogtest
*/
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <strings.h>
#include <syslog.h>
#include <unistd.h>
#include <sys/time.h>
#include <sys/types.h>
#include <sys/socket.h>
#include <ctype.h>
#include <netinet/in.h>
#define LISTEN_PORT 10000
int f_no_seqno = 0; /* Set to disable printing sequence numbers in msgs */
struct facility_def {
char *symbol;
int value;
} facility_table[] = {
{"AUTH", LOG_AUTH},
{"DAEMON", LOG_DAEMON},
{"KERN", LOG_KERN},
{"LPR", LOG_LPR},
{"MAIL", LOG_MAIL},
{"NEWS", LOG_NEWS},
{"UUCP", LOG_UUCP},
{"USER", LOG_USER},
{"LOCAL0", LOG_LOCAL0},
{"LOCAL1", LOG_LOCAL1},
{"LOCAL2", LOG_LOCAL2},
{"LOCAL3", LOG_LOCAL3},
{"LOCAL4", LOG_LOCAL4},
{"LOCAL5", LOG_LOCAL5},
{"LOCAL6", LOG_LOCAL6},
{"LOCAL7", LOG_LOCAL7},
{NULL, 0}
};
struct level_def {
char *symbol;
int value;
} level_table[] = {
{"ALERT", LOG_ALERT},
{"CRIT", LOG_CRIT},
{"DEBUG", LOG_DEBUG},
{"EMERG", LOG_EMERG},
{"ERR", LOG_ERR},
{"INFO", LOG_INFO},
{"NOTICE", LOG_NOTICE},
{"WARNING", LOG_WARNING},
{NULL, 0}
};
struct running_time {
long int sec;
long int msec;
long int usec;
};
void printFacilities(void) {
int col;
struct facility_def *facilityDef;
for (facilityDef = facility_table, col = 0;
facilityDef->symbol;
col = (col + 1) % 4, facilityDef++)
fprintf(stderr, "%15s%s", facilityDef->symbol,
(col == 3 ? "\n" : ""));
if (col != 3)
fprintf(stderr, "\n");
return;
}
void printLevels(void) {
int col;
struct level_def *levelDef;
for (levelDef = level_table, col = 0;
levelDef->symbol;
col = (col + 1) % 4, levelDef++)
fprintf(stderr, "%15s%s", levelDef->symbol,
(col == 3 ? "\n" : ""));
if (col != 3)
fprintf(stderr, "\n");
return;
}
void printUsage(void) {
fprintf(stderr, "usage: syslogtest facility level repetitions sleep [s]\n\n");
fprintf(stderr, "\trepetitions\t\tNumber of messages to send.\n");
fprintf(stderr, "\tsleep\t\tTime to wait between sending messages.\n");
fprintf(stderr,
"\ts\t\tBecome a daemon (for use with 'master' client)\n\n");
fprintf(stderr, "FACILITIES:\n");
printFacilities();
fprintf(stderr, "LEVELS:\n");
printLevels();
return;
}
int priorityFromFacilityLevel(const char *facility,
const char *level) {
int pri = -1;
int lev = -1;
struct facility_def *fd_current = facility_table;
struct level_def *ld_current = level_table;
while (fd_current->symbol) {
if (!strcmp(fd_current->symbol, facility)) {
pri = fd_current->value;
break;
}
fd_current++;
}
if (pri < 0)
return -1;
while (ld_current->symbol) {
if (!strcmp(ld_current->symbol, level)) {
lev = ld_current->value;
break;
}
ld_current++;
}
if (lev < -1)
return -1;
pri |= lev;
return pri;
}
int promptForPriority(void) {
char s_fac[100];
char s_lev[100];
printf("Enter facility: ");
fgets(s_fac, sizeof(s_fac), stdin);
s_fac[strlen(s_fac) - 1] = '\0';
printf("Enter level: ");
fgets(s_lev, sizeof(s_lev), stdin);
s_lev[strlen(s_lev) - 1] = '\0';
return priorityFromFacilityLevel(s_fac, s_lev);
}
int promptForRepetitions(void) {
char s_inp[100];
printf("Enter number of repetitions: ");
fgets(s_inp, sizeof(s_inp), stdin);
return atoi(s_inp);
}
struct running_time computeRunningTime(struct timeval *tv_start,
struct timeval *tv_end) {
long int total_usec;
struct running_time rt;
total_usec = tv_end->tv_sec;
total_usec -= tv_start->tv_sec;
total_usec *= 1000000;
total_usec -= tv_start->tv_usec;
total_usec += tv_end->tv_usec;
rt.sec = total_usec / 1000000;
rt.usec = total_usec - (rt.sec * 1000000);
rt.msec = rt.usec / 1000;
rt.usec = rt.usec - (rt.msec * 1000);
return rt;
}
int waitForGoSignal(int fd_client) {
char buf[10];
if (read(fd_client, &buf, sizeof(buf)) <= 0)
return 0;
if (tolower(buf[0]) == 'g' && tolower(buf[1]) == 'o')
return 1;
if (!strncasecmp(buf, "stop", 4))
return 2;
return 0;
}
void runTest(int pri, int i_nReps, int sleep) {
int i;
char report[1024];
struct timeval tv_start, tv_end;
struct running_time rt;
gettimeofday(&tv_start, NULL);
for (i = 0; i < i_nReps; i++) {
if (f_no_seqno)
syslog(pri, "TEST MESSAGE", i, i);
else
syslog(pri, "(%d) TEST MESSAGE (%d)", i, i);
if (sleep)
usleep(sleep);
}
gettimeofday(&tv_end, NULL);
/* Report results */
rt = computeRunningTime(&tv_start, &tv_end);
snprintf(report, sizeof(report),
"REPS: %d Time: %ld s %ld ms %ld us", i_nReps, rt.sec,
rt.msec, rt.usec);
printf("[%d]: %s\n", (int) getpid(), report);
syslog(pri, report);
}
void err(char *errstr) {
int pri = LOG_ERR | LOG_USER;
fputs(errstr, stderr);
syslog(pri, errstr);
return;
}
static char *basename(char *str) {
char *end = str + strlen(str);
while(end > str && *end != '/')
end--;
if (*end == '/')
end++;
return end;
}
int main(int argc, char *argv[]) {
int i;
int pri = -1;
int i_nReps = 0;
int sleep = 0;
int optval = 1;
int sync = 0; /* Synchronized operation */
int fd_listen = -1, fd_client = -1;
struct sockaddr_in sa_listen, sa_client;
/* printf("BASENAME: %s\n", basename(argv[0])); */
if (!strcmp(basename(argv[0]), "lasttest"))
f_no_seqno = 1;
for (i=1; i<argc; i++)
if (!strcmp(argv[i], "-h")) {
printUsage();
return 1;
}
if (argc < 3) {
pri = promptForPriority();
}
else {
pri = priorityFromFacilityLevel(argv[1], argv[2]);
}
if (pri < 0) {
err("No facility and priority set.\n");
printUsage();
return 1;
}
if (argc > 3)
i_nReps = atoi(argv[3]);
else
i_nReps = promptForRepetitions();
if (argc > 4)
sleep = atoi(argv[4]);
if (argc > 5)
if (!strcmp(argv[5], "s"))
sync = 1;
openlog("TEST", LOG_PID, pri);
if (i_nReps < 1) {
err("No repetitions indicated- nothing to do.");
printUsage();
return 1;
}
if (sync) {
if ((fd_listen = socket(AF_INET, SOCK_STREAM, 0)) < 0) {
char *s_err = "Couldn't get socket.";
fprintf(stderr, "%s\n", s_err);
pri = LOG_ERR;
syslog(pri, s_err);
return 1;
}
setsockopt(fd_listen, SOL_SOCKET, SO_REUSEADDR, &optval,
sizeof(optval));
bzero(&sa_listen, sizeof(sa_listen));
sa_listen.sin_family = AF_INET;
sa_listen.sin_port = htons(LISTEN_PORT);
sa_listen.sin_addr.s_addr = INADDR_ANY;
if (bind(fd_listen, (struct sockaddr*) &sa_listen,
sizeof(sa_listen)) < 0) {
err("Couldn't bind listen port.");
close(fd_listen);
return 1;
}
if (listen(fd_listen, 5) < 0) {
err("Can't listen on listening socket.");
close(fd_listen);
return 1;
}
}
if (!sync) {
runTest(pri, i_nReps, sleep);
}
else {
int quit = 1;
while(quit != 2) {
optval = sizeof(sa_client);
bzero(&sa_client, sizeof(sa_client));
if ((fd_client = accept(fd_listen,
(struct sockaddr*) &sa_client,
(size_t*) &optval)) < 0) {
err("Can't accept connection.");
close(fd_listen);
return 1;
}
while((quit = waitForGoSignal(fd_client)) == 1) {
runTest(pri, i_nReps, sleep);
if (fork())
exit(0); /* To change PID for next test. */
}
close(fd_client);
}
close(fd_listen);
}
closelog();
return 0;
}
--Qxx1br4bt0+wmkIi
Content-Type: text/plain; charset=us-ascii
Content-Disposition: attachment; filename="master.c"
/* master.c
*
* By Jonathan Marks
* j-marks@uiuc.edu
*
* Compiling:
* Solaris: cc master.c -o master -lxnet
* AIX: cc master.c -o master
*/
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <strings.h>
#include <syslog.h>
#include <unistd.h>
#include <sys/time.h>
#include <sys/types.h>
#include <sys/socket.h>
#include <ctype.h>
#include <netinet/in.h>
#include <errno.h>
#include <arpa/inet.h>
#include <netdb.h> /* For gethostbyname() */
#define SERVER_PORT 10000
#define CFG_FILE "servers"
typedef struct {
int fd; /* File descriptor for server */
char *servername; /* Name of server */
struct in_addr address; /* Net-byte-order address for host. */
} server_def;
int n_server_defs = 0;
server_def *server_table = NULL;
int read_config_file() {
char buf[1024];
char s_serverName[1024];
FILE *f_cfg;
struct hostent *he_server;
if (!(f_cfg = fopen(CFG_FILE, "r"))) {
fprintf(stderr, "Can't open config file: %s\n",
strerror(errno));
return 0;
}
while(fgets(buf, sizeof(buf), f_cfg)) {
if (sscanf(buf, "%s", s_serverName) < 1) {
fprintf(stderr, "REJECTED config file line: %s\n", buf);
continue;
}
/* Strip newline */
if (s_serverName[strlen(s_serverName) - 1] == '\n')
s_serverName[strlen(s_serverName) - 1] = '\0';
if (!(he_server = gethostbyname(s_serverName))) {
fprintf(stderr,
"REJECTED server %s: Can't look it up.\n", s_serverName);
continue;
}
n_server_defs++;
server_table = (server_def*)
realloc(server_table, sizeof(server_def) * n_server_defs);
server_table[n_server_defs - 1].servername = strdup(s_serverName);
server_table[n_server_defs - 1].address =
*((struct in_addr*)(he_server->h_addr_list[0]));
server_table[n_server_defs - 1].fd = -1;
fprintf(stderr, "ACCEPTED server %s (%s)\n", s_serverName,
inet_ntoa(server_table[n_server_defs - 1].address));
}
if (n_server_defs)
return 1;
return 0;
}
void give_go_signal(void) {
int i;
for(i=0; i<n_server_defs; i++)
if (server_table[i].fd > 0)
if(write(server_table[i].fd, "go\n", 3) < 0) {
fprintf(stderr, "ERROR sending GO signal to %s: %s\n",
server_table[i].servername, strerror(errno));
close(server_table[i].fd);
server_table[i].fd = -1;
}
return;
}
void give_stop_signal(void) {
int i;
for(i=0; i<n_server_defs; i++)
if (server_table[i].fd > 0)
if(write(server_table[i].fd, "stop\n", 5) < 0) {
fprintf(stderr, "ERROR sending STOP signal to %s: %s\n",
server_table[i].servername, strerror(errno));
close(server_table[i].fd);
server_table[i].fd = -1;
}
return;
}
void take_user_commands(void) {
char s_inp[100];
int more_commands = 1;
while(more_commands) {
printf("(h for help)>>> ");
fgets(s_inp, sizeof(s_inp), stdin);
if (s_inp[strlen(s_inp) - 1] == '\n')
s_inp[strlen(s_inp) - 1] = '\0';
if (!strcmp(s_inp, "h")) {
/* Show help */
printf("\th\t\tShow help\n");
printf("\tgo\t\tGive GO signal to all servers.\n");
printf("\tstop\t\tGive STOP signal to all servers, then quit.\n");
printf("\tquit\t\tQuit (without stopping servers.\n");
}
else if (!strcmp(s_inp, "go")) {
give_go_signal();
}
else if (!strcmp(s_inp, "stop")) {
/* Stop servers and quit */
give_stop_signal();
more_commands = 0;
}
else if (!strcmp(s_inp, "quit")) {
/* Exit without stopping servers */
more_commands = 0;
}
else {
/* Don't know what they typed */
printf("Sorry, unrecognized command. Type 'h' for help.\n");
}
}
return;
}
int main(int argc, char *argv[]) {
int i;
struct sockaddr_in sa_server;
if (!read_config_file()) {
fprintf(stderr, "No server definitions. Exiting.\n");
return 1;
}
/* Open connections to each server */
for(i=0; i<n_server_defs; i++) {
int fd_tmp, j;
printf("Connecting to %s..\n", server_table[i].servername);
if ((fd_tmp = socket(AF_INET, SOCK_STREAM, 0)) < 0) {
fprintf(stderr, "Can't create a socket for a server: %s\n",
strerror(errno));
for(j=0; j<i; j++)
close(server_table[i].fd);
return 1;
}
bzero(&sa_server, sizeof(sa_server));
sa_server.sin_family = AF_INET;
sa_server.sin_port = htons(SERVER_PORT);
sa_server.sin_addr = server_table[i].address;
if (connect(fd_tmp, (struct sockaddr*) &sa_server,
sizeof(sa_server)) < 0) {
fprintf(stderr, "Can't connect to server %s: %s. Aborting.\n",
server_table[i].servername, strerror(errno));
for(j=0; j<i; j++)
close(server_table[j].fd);
close(fd_tmp);
return 1;
}
server_table[i].fd = fd_tmp;
}
printf("Connected to all servers.\n");
take_user_commands(); /* command reading loop. */
for(i=0; i<n_server_defs; i++)
close(server_table[i].fd);
return 0;
}
--Qxx1br4bt0+wmkIi
Content-Type: text/plain; charset=us-ascii
Content-Disposition: attachment; filename=results
#!/usr/local/bin/perl -w
#
# results
#
# By Jonathan Marks
# j-marks@uiuc.edu
#
use strict 'vars';
my ($logname, $pid, $numTrials) = @ARGV;
die "No log name\n" if !$logname;
die "No PID\n" if !$pid;
die "No number of trials\n" if !$numTrials;
my @missingTrials;
my $nextExpected = 0;
my $current = -1;
my $count = 0;
my $line;
open(LOGFILE, "<$logname") or die "Can't open $logname: $!\n";
while ($count < $numTrials && ($line = <LOGFILE>)) {
next if ($line !~ m/TEST\[$pid]:.*\((\d+)\) TEST MESSAGE/);
$current = $1;
$count++;
if ($current > $nextExpected) {
countMissing($current, $nextExpected);
}
$nextExpected = $current + 1;
}
close LOGFILE;
countMissing($numTrials, $nextExpected) if ($current != $numTrials - 1);
print "Missing trials:\n";
open(FMT, "| /usr/bin/fmt") or
die "Can't run /usr/bin/fmt: $!\n";
map { print FMT "$_ " } @missingTrials;
close FMT;
print "\n";
print "Total found: $count (missing " . ($numTrials - $count) . ")\n";
sub countMissing {
my ($cur, $expected) = @_;
my $i;
for ($i = $expected; $i < $cur; $i++) {
# Do nothing.. Just count
}
my $missingStr = "$expected";
$missingStr .= "-" . ($i - 1) if ($i != ($expected + 1));
push @missingTrials, $missingStr;
}
--Qxx1br4bt0+wmkIi--