Created
April 4, 2011 23:13
-
-
Save jrockway/902677 to your computer and use it in GitHub Desktop.
perl vs. c for syslog protocol
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
#include <errno.h> | |
#include <netinet/in.h> | |
#include <stdio.h> | |
#include <stdlib.h> | |
#include <string.h> | |
#include <sys/socket.h> | |
#include <sys/time.h> | |
#include <sys/types.h> | |
#include <time.h> | |
#define ITERATIONS 1000000 | |
#define LEN 10 | |
int main(void) { | |
int i, s; | |
size_t wrote, sent; | |
struct sockaddr_in dest; | |
char timebuf[30]; | |
char buf[LEN]; | |
struct timespec start, end; | |
struct timeval now_tv; | |
struct timezone now_tz; | |
struct tm *now_tm; | |
double time; | |
long iters; | |
dest.sin_family = AF_INET; | |
dest.sin_port = htons(1234); | |
if( inet_aton("127.0.0.1", &dest.sin_addr) == 0 ){ | |
fprintf(stderr, "inet_aton: %s\n", strerror(errno)); | |
return 1; | |
} | |
s = socket(AF_INET, SOCK_DGRAM, IPPROTO_UDP); | |
if(s < 0){ | |
fprintf(stderr, "socket: %s\n", strerror(errno)); | |
return 1; | |
} | |
if( clock_gettime(CLOCK_REALTIME, &start) == -1 ){ | |
fprintf(stderr, "gettime: %s", strerror(errno)); | |
return 1; | |
} | |
for(i = 0; i < ITERATIONS; i++){ | |
if( gettimeofday(&now_tv, &now_tz) == -1 ){ | |
fprintf(stderr, "gettimeofday: %s", strerror(errno)); | |
return 1; | |
} | |
now_tm = localtime(&now_tv.tv_sec); | |
if(now_tm == NULL){ | |
fprintf(stderr, "localtime: %s", strerror(errno)); | |
return 1; | |
} | |
memset( timebuf, (char) 0, sizeof(timebuf) ); | |
if( strftime(timebuf, sizeof(timebuf), "%h %e %T", now_tm) < 5 ){ | |
fprintf(stderr, "strftime too short: %s", strerror(errno)); | |
return 1; | |
} | |
memset( buf, (char) 0, sizeof(buf) ); | |
wrote = snprintf(buf, sizeof(buf), | |
"<%d>%s %s %s[%d]: %s", | |
7, timebuf, "sender", "name", 1234, | |
"this is an example log message!"); | |
if(wrote == LEN) buf[LEN - 1] = 0; | |
sent = sendto(s, buf, sizeof(buf), 0, | |
(struct sockaddr *) &dest, sizeof(dest)); | |
if(sent != LEN){ | |
fprintf(stderr, "wrong size write: %s\n", strerror(errno)); | |
return 1; | |
} | |
} | |
if( clock_gettime(CLOCK_REALTIME, &end) == -1 ){ | |
fprintf(stderr, "gettime: %s", strerror(errno)); | |
} | |
time = ( end.tv_sec + end.tv_nsec/1000000000.0d) - | |
(start.tv_sec + start.tv_nsec/1000000000.0d); | |
iters = ITERATIONS / time; | |
printf("time taken: %f (%d / second)\n", time, iters); | |
return 0; | |
} |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
#!/usr/bin/env perl | |
use strict; | |
use warnings; | |
use feature ':5.10'; | |
use Time::HiRes qw(time); | |
use POSIX qw(strftime); | |
use Socket; | |
my $dest = sockaddr_in('1234', inet_aton('localhost')); | |
my $iterations = 1000000; | |
socket my $socket, AF_INET, SOCK_DGRAM, getprotobyname('udp') | |
or die $!; | |
my $start = time(); | |
for(1..$iterations){ | |
my $t = strftime('%h %e %T', localtime); | |
my $msg = sprintf '<%d>%s %s %s[%d]: %s', 7, $t, 'sender', 'name', $$, | |
'this is an example log message!'; | |
send $socket, $msg, 0, $dest or die $!; | |
} | |
my $time = time() - $start; | |
printf("%d took %f2: %d per second\n", $iterations, $time, $iterations/$time); |
Nice. I wonder if the same optimization can be performed without segfaulting randomly.
If there are additional bugs past what you've pointed out, do let me know.
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Maybe the benchmark should actually test the module in question? Your perl test omits the most important optimization in it, which skips the strftime call if the time hasn't changed since the last send. Rather than being plagued by overhead, Log::Syslog::Fast handily beats your C version.
sock.pl
1000000 took 53.1618412: 18810 per second
12.748u 29.697s 0:53.18 79.7% 0+0k 0+0io 0pf+0w
sock.c:
time taken: 28.074753 (35619 / second)
4.760u 22.609s 0:28.07 97.4% 0+0k 0+0io 0pf+0w
lsf.pl (https://gist.github.com/902718):
1000000 took 21.2284342: 47106 per second
2.656u 8.984s 0:20.16 57.6% 0+0k 0+0io 0pf+0w