From 5fd1d7de9cc163a73f10b626da2b656860e98615 Mon Sep 17 00:00:00 2001 From: Daniel Roethlisberger Date: Fri, 21 Nov 2014 12:03:08 +0100 Subject: [PATCH 1/2] Rename flags for clarity --- log.c | 4 ++-- main.c | 14 +++++++------- opts.h | 4 ++-- 3 files changed, 11 insertions(+), 11 deletions(-) diff --git a/log.c b/log.c index 2230408..1660c10 100644 --- a/log.c +++ b/log.c @@ -578,10 +578,10 @@ int log_preinit(opts_t *opts) { if (opts->contentlog) { - if (opts->contentlogdir) { + if (opts->contentlog_isdir) { if (log_content_open_logdir(opts->contentlog) == -1) goto out; - } else if (opts->contentlogspec) { + } else if (opts->contentlog_isspec) { if (log_content_open_logspec(opts->contentlog) == -1) goto out; } else { diff --git a/main.c b/main.c index d5a2328..3bb9e1c 100644 --- a/main.c +++ b/main.c @@ -502,8 +502,8 @@ main(int argc, char *argv[]) opts->contentlog = strdup(optarg); if (!opts->contentlog) oom_die(argv0); - opts->contentlogdir = 0; - opts->contentlogspec = 0; + opts->contentlog_isdir = 0; + opts->contentlog_isspec = 0; break; case 'S': if (opts->contentlog) @@ -511,8 +511,8 @@ main(int argc, char *argv[]) opts->contentlog = strdup(optarg); if (!opts->contentlog) oom_die(argv0); - opts->contentlogdir = 1; - opts->contentlogspec = 0; + opts->contentlog_isdir = 1; + opts->contentlog_isspec = 0; break; case 'F': if (opts->contentlog) @@ -520,8 +520,8 @@ main(int argc, char *argv[]) opts->contentlog = strdup(optarg); if (!opts->contentlog) oom_die(argv0); - opts->contentlogdir = 0; - opts->contentlogspec = 1; + opts->contentlog_isdir = 0; + opts->contentlog_isspec = 1; break; #ifdef HAVE_LOCAL_PROCINFO case 'i': @@ -619,7 +619,7 @@ main(int argc, char *argv[]) oom_die(argv0); } if (!opts->dropuser && !geteuid() && !getuid() && - !opts->contentlogdir && !opts->contentlogspec) { + !opts->contentlog_isdir && !opts->contentlog_isspec) { opts->dropuser = strdup("nobody"); if (!opts->dropuser) oom_die(argv0); diff --git a/opts.h b/opts.h index 1d98c92..abbf5e8 100644 --- a/opts.h +++ b/opts.h @@ -75,8 +75,8 @@ typedef struct opts { #endif /* SSL_OP_NO_TLSv1_2 */ unsigned int passthrough : 1; unsigned int deny_ocsp : 1; - unsigned int contentlogdir : 1; - unsigned int contentlogspec : 1; + unsigned int contentlog_isdir : 1; + unsigned int contentlog_isspec : 1; #ifdef HAVE_LOCAL_PROCINFO unsigned int lprocinfo : 1; #endif /* HAVE_LOCAL_PROCINFO */ From b5e3856a975ea40f814e8039a74246bd20acd764 Mon Sep 17 00:00:00 2001 From: Daniel Roethlisberger Date: Fri, 21 Nov 2014 16:10:37 +0100 Subject: [PATCH 2/2] Move open() and mkdir() to logger thread --- log.c | 393 ++++++++++++++++++++++++++++++++++++------------------ log.h | 43 ++++-- logbuf.c | 33 +++-- logbuf.h | 18 ++- logger.c | 104 ++++++++++++--- logger.h | 35 +++-- pxyconn.c | 27 ++-- 7 files changed, 446 insertions(+), 207 deletions(-) diff --git a/log.c b/log.c index 1660c10..aa28659 100644 --- a/log.c +++ b/log.c @@ -62,7 +62,7 @@ static int err_started = 0; /* while 0, shortcut the thrqueue */ static int err_mode = LOG_ERR_MODE_STDERR; static ssize_t -log_err_writecb(UNUSED int fd, const void *buf, size_t sz) +log_err_writecb(UNUSED void *fh, const void *buf, size_t sz) { switch (err_mode) { case LOG_ERR_MODE_STDERR: @@ -87,9 +87,10 @@ log_err_printf(const char *fmt, ...) if (rv < 0) return -1; if (err_started) { - return logger_write_freebuf(err_log, 0, buf, strlen(buf) + 1); + return logger_write_freebuf(err_log, NULL, 0, + buf, strlen(buf) + 1); } else { - log_err_writecb(0, (unsigned char*)buf, strlen(buf) + 1); + log_err_writecb(NULL, (unsigned char*)buf, strlen(buf) + 1); free(buf); } return 0; @@ -117,9 +118,9 @@ log_dbg_write_free(void *buf, size_t sz) return 0; if (err_started) { - return logger_write_freebuf(err_log, 0, buf, sz); + return logger_write_freebuf(err_log, NULL, 0, buf, sz); } else { - log_err_writecb(0, buf, sz); + log_err_writecb(NULL, buf, sz); free(buf); } return 0; @@ -183,7 +184,7 @@ log_connect_open(const char *logfile) * resolution that should not make any difference. */ static ssize_t -log_connect_writecb(UNUSED int fd, const void *buf, size_t sz) +log_connect_writecb(UNUSED void *fh, const void *buf, size_t sz) { char timebuf[32]; time_t epoch; @@ -216,16 +217,38 @@ log_connect_close(void) * Content log. * Logs connection content to either a single file or a directory containing * per-connection logs. - * Uses a logger thread. + * Uses a logger thread; the actual logging happens in a separate thread. + * To ensure ordering of requests (open, write, ..., close), logging for a + * single connection must happen from a single thread. + * This is guaranteed by the current pxythr architecture. */ +#define PREPFLAG_OUTBOUND 1 + +struct log_content_ctx { + unsigned int open : 1; + int fd; + union { + struct { + char *header_in; + char *header_out; + } file; + struct { + char *filename; + } dir; + struct { + char *filename; + } spec; + } u; +}; + logger_t *content_log = NULL; static int content_fd = -1; /* if set, we are in single file mode */ static const char *content_basedir = NULL; static const char *content_logspec = NULL; static int -log_content_open_singlefile(const char *logfile) +log_content_file_preinit(const char *logfile) { content_fd = open(logfile, O_WRONLY|O_APPEND|O_CREAT, 0660); if (content_fd == -1) { @@ -237,21 +260,21 @@ log_content_open_singlefile(const char *logfile) } static int -log_content_open_logdir(const char *basedir) +log_content_dir_preinit(const char *basedir) { content_basedir = basedir; return 0; } static int -log_content_open_logspec(const char *logspec) +log_content_spec_preinit(const char *logspec) { content_logspec = logspec; return 0; } static void -log_content_close_singlefile(void) +log_content_file_fini(void) { if (content_fd != -1) { close(content_fd); @@ -389,130 +412,257 @@ log_content_format_pathspec(const char *logspec, char *srcaddr, char *dstaddr, #undef PATH_BUF_INC int -log_content_open(log_content_ctx_t *ctx, char *srcaddr, char *dstaddr, +log_content_open(log_content_ctx_t **pctx, opts_t *opts, + char *srcaddr, char *dstaddr, char *exec_path, char *user, char *group) { - if (ctx->open) - return 0; - - if (content_fd != -1) { - /* single-file content log (-L) */ - ctx->fd = content_fd; - if (asprintf(&ctx->header_in, "%s -> %s", - srcaddr, dstaddr) < 0) { - return -1; - } - if (asprintf(&ctx->header_out, "%s -> %s", - dstaddr, srcaddr) < 0) { - free(ctx->header_in); - return -1; - } - } else if (content_logspec) { - /* per-connection-file content log with logspec (-F) */ - char *filename, *filedir; - - filename = log_content_format_pathspec(content_logspec, - srcaddr, dstaddr, - exec_path, user, group); - if (!filename) { - return -1; - } + log_content_ctx_t *ctx; - filedir = dirname(filename); - if (!filedir || sys_mkpath(filedir, 0755) == -1) { - log_err_printf("Could not create directory '%s': %s\n", - filedir, strerror(errno)); - free(filename); - return -1; - } + if (*pctx) + return 0; + *pctx = malloc(sizeof(log_content_ctx_t)); + if (!*pctx) + return -1; + ctx = *pctx; - ctx->fd = open(filename, O_WRONLY|O_APPEND|O_CREAT, 0660); - if (ctx->fd == -1) { - log_err_printf("Failed to open '%s': %s\n", - filename, strerror(errno)); - free(filename); - return -1; - } - free(filename); - } else { + if (opts->contentlog_isdir) { /* per-connection-file content log (-S) */ - char filename[1024]; char timebuf[24]; time_t epoch; struct tm *utc; if (time(&epoch) == -1) { log_err_printf("Failed to get time\n"); - return -1; + goto errout; } if ((utc = gmtime(&epoch)) == NULL) { - log_err_printf("Failed to convert time: %s\n", - strerror(errno)); - return -1; + log_err_printf("Failed to convert time: %s (%i)\n", + strerror(errno), errno); + goto errout; } if (!strftime(timebuf, sizeof(timebuf), "%Y%m%dT%H%M%SZ", utc)) { - log_err_printf("Failed to format time: %s\n", - strerror(errno)); - return -1; + log_err_printf("Failed to format time: %s (%i)\n", + strerror(errno), errno); + goto errout; } - if (snprintf(filename, sizeof(filename), "%s/%s-%s-%s.log", + if (asprintf(&ctx->u.dir.filename, "%s/%s-%s-%s.log", content_basedir, timebuf, srcaddr, dstaddr) < 0) { - log_err_printf("Failed to format filename: %s\n", - strerror(errno)); - return -1; + log_err_printf("Failed to format filename: %s (%i)\n", + strerror(errno), errno); + goto errout; } - ctx->fd = open(filename, O_WRONLY|O_APPEND|O_CREAT, 0660); - if (ctx->fd == -1) { - log_err_printf("Failed to open '%s': %s\n", - filename, strerror(errno)); - return -1; + } else if (opts->contentlog_isspec) { + /* per-connection-file content log with logspec (-F) */ + ctx->u.spec.filename = log_content_format_pathspec( + content_logspec, + srcaddr, dstaddr, + exec_path, user, group); + if (!ctx->u.spec.filename) { + goto errout; + } + } else { + /* single-file content log (-L) */ + ctx->fd = content_fd; + if (asprintf(&ctx->u.file.header_in, "%s -> %s", + srcaddr, dstaddr) < 0) { + goto errout; + } + if (asprintf(&ctx->u.file.header_out, "%s -> %s", + dstaddr, srcaddr) < 0) { + free(ctx->u.file.header_in); + goto errout; } } + + /* submit an open event */ + if (logger_open(content_log, ctx) == -1) + goto errout; ctx->open = 1; return 0; +errout: + free(ctx); + *pctx = NULL; + return -1; } void -log_content_submit(log_content_ctx_t *ctx, logbuf_t *lb, int direction) +log_content_submit(log_content_ctx_t *ctx, logbuf_t *lb, int is_outbound) { - logbuf_t *head; - time_t epoch; - struct tm *utc; - char *header; + unsigned long prepflags = 0; if (!ctx->open) { log_err_printf("log_content_submit called on closed ctx\n"); return; } - if (!(header = direction ? ctx->header_out : ctx->header_in)) + if (is_outbound) + prepflags |= PREPFLAG_OUTBOUND; + logger_submit(content_log, ctx, prepflags, lb); +} + +void +log_content_close(log_content_ctx_t **pctx) +{ + if (!(*pctx)->open) + return; + logger_close(content_log, *pctx); + *pctx = NULL; +} + +/* + * Callback functions that are executed in the logger thread. + */ + +static ssize_t +log_content_common_writecb(void *fh, const void *buf, size_t sz) +{ + log_content_ctx_t *ctx = fh; + + if (write(ctx->fd, buf, sz) == -1) { + log_err_printf("Warning: Failed to write to content log: %s\n", + strerror(errno)); + return -1; + } + return 0; +} + +static int +log_content_dir_opencb(void *fh) +{ + log_content_ctx_t *ctx = fh; + + ctx->fd = open(ctx->u.dir.filename, O_WRONLY|O_APPEND|O_CREAT, 0660); + if (ctx->fd == -1) { + log_err_printf("Failed to open '%s': %s (%i)\n", + ctx->u.dir.filename, strerror(errno), errno); + return -1; + } + return 0; +} + +static void +log_content_dir_closecb(void *fh) +{ + log_content_ctx_t *ctx = fh; + + if (ctx->u.dir.filename) + free(ctx->u.dir.filename); + if (ctx->fd != 1) + close(ctx->fd); + free(ctx); +} + +static int +log_content_spec_opencb(UNUSED void *fh) +{ + log_content_ctx_t *ctx = fh; + char *filedir, *filename2; + + filename2 = strdup(ctx->u.spec.filename); + if (!filename2) { + log_err_printf("Could not duplicate filname: %s (%i)\n", + strerror(errno), errno); + return -1; + } + filedir = dirname(filename2); + if (!filedir) { + log_err_printf("Could not get dirname: %s (%i)\n", + strerror(errno), errno); + free(filename2); + return -1; + } + if (sys_mkpath(filedir, 0755) == -1) { + log_err_printf("Could not create directory '%s': %s (%i)\n", + filedir, strerror(errno), errno); + free(filename2); + return -1; + } + free(filename2); + + ctx->fd = open(ctx->u.spec.filename, O_WRONLY|O_APPEND|O_CREAT, 0660); + if (ctx->fd == -1) { + log_err_printf("Failed to open '%s': %s\n", + ctx->u.spec.filename, strerror(errno)); + return -1; + } + + return 0; +} + +static void +log_content_spec_closecb(void *fh) +{ + log_content_ctx_t *ctx = fh; + + if (ctx->u.spec.filename) + free(ctx->u.spec.filename); + if (ctx->fd != -1) + close(ctx->fd); + free(ctx); +} + +/* +static int +log_content_file_opencb(void *fh) +{ + return 0; +} +*/ + +static void +log_content_file_closecb(void *fh) +{ + log_content_ctx_t *ctx = fh; + + if (ctx->u.file.header_in) { + free(ctx->u.file.header_in); + } + if (ctx->u.file.header_out) { + free(ctx->u.file.header_out); + } + + free(ctx); +} + +static logbuf_t * +log_content_file_prepcb(void *fh, unsigned long prepflags, logbuf_t *lb) +{ + log_content_ctx_t *ctx = fh; + int is_outbound = !!(prepflags & PREPFLAG_OUTBOUND); + logbuf_t *head; + time_t epoch; + struct tm *utc; + char *header; + + if (!(header = is_outbound ? ctx->u.file.header_out + : ctx->u.file.header_in)) goto out; /* prepend size tag and newline */ - head = logbuf_new_printf(lb->fd, lb, " (%zu):\n", logbuf_size(lb)); + head = logbuf_new_printf(lb->fh, lb, " (%zu):\n", logbuf_size(lb)); if (!head) { log_err_printf("Failed to allocate memory\n"); logbuf_free(lb); - return; + return NULL; } lb = head; /* prepend header */ - head = logbuf_new_copy(header, strlen(header), lb->fd, lb); + head = logbuf_new_copy(header, strlen(header), lb->fh, lb); if (!head) { log_err_printf("Failed to allocate memory\n"); logbuf_free(lb); - return; + return NULL; } lb = head; /* prepend timestamp */ - head = logbuf_new_alloc(32, lb->fd, lb); + head = logbuf_new_alloc(32, lb->fh, lb); if (!head) { log_err_printf("Failed to allocate memory\n"); logbuf_free(lb); - return; + return NULL; } lb = head; time(&epoch); @@ -521,47 +671,7 @@ log_content_submit(log_content_ctx_t *ctx, logbuf_t *lb, int direction) utc); out: - lb->fd = ctx->fd; - logger_submit(content_log, lb); -} - -void -log_content_close(log_content_ctx_t *ctx) -{ - if (!ctx->open) - return; - if (content_fd == -1) { - logger_write_freebuf(content_log, ctx->fd, NULL, 0); - } - if (ctx->header_in) { - free(ctx->header_in); - } - if (ctx->header_out) { - free(ctx->header_out); - } - ctx->open = 0; -} - -/* - * Do the actual write to the open connection log file descriptor. - * We prepend a timestamp here, which means that timestamps are slightly - * delayed from the time of actual logging. Since we only have second - * resolution that should not make any difference. - */ -static ssize_t -log_content_writecb(int fd, const void *buf, size_t sz) -{ - if (!buf) { - close(fd); - return 0; - } - - if (write(fd, buf, sz) == -1) { - log_err_printf("Warning: Failed to write to content log: %s\n", - strerror(errno)); - return -1; - } - return 0; + return lb; } @@ -577,37 +687,56 @@ log_content_writecb(int fd, const void *buf, size_t sz) int log_preinit(opts_t *opts) { + logger_open_func_t opencb; + logger_close_func_t closecb; + logger_write_func_t writecb; + logger_prep_func_t prepcb; + if (opts->contentlog) { if (opts->contentlog_isdir) { - if (log_content_open_logdir(opts->contentlog) == -1) + if (log_content_dir_preinit(opts->contentlog) == -1) goto out; + opencb = log_content_dir_opencb; + closecb = log_content_dir_closecb; + writecb = log_content_common_writecb; + prepcb = NULL; } else if (opts->contentlog_isspec) { - if (log_content_open_logspec(opts->contentlog) == -1) + if (log_content_spec_preinit(opts->contentlog) == -1) goto out; + opencb = log_content_spec_opencb; + closecb = log_content_spec_closecb; + writecb = log_content_common_writecb; + prepcb = NULL; } else { - if (log_content_open_singlefile(opts->contentlog) == -1) + if (log_content_file_preinit(opts->contentlog) == -1) goto out; + opencb = NULL; + closecb = log_content_file_closecb; + writecb = log_content_common_writecb; + prepcb = log_content_file_prepcb; } - if (!(content_log = logger_new(log_content_writecb))) { - log_content_close_singlefile(); + if (!(content_log = logger_new(opencb, closecb, writecb, + prepcb))) { + log_content_file_fini(); goto out; } } if (opts->connectlog) { if (log_connect_open(opts->connectlog) == -1) goto out; - if (!(connect_log = logger_new(log_connect_writecb))) { + if (!(connect_log = logger_new(NULL, NULL, + log_connect_writecb, NULL))) { log_connect_close(); goto out; } } - if (!(err_log = logger_new(log_err_writecb))) + if (!(err_log = logger_new(NULL, NULL, log_err_writecb, NULL))) goto out; return 0; out: if (content_log) { - log_content_close_singlefile(); + log_content_file_fini(); logger_free(content_log); } if (connect_log) { @@ -665,7 +794,7 @@ log_fini(void) logger_free(err_log); if (content_log) - log_content_close_singlefile(); + log_content_file_fini(); if (connect_log) log_connect_close(); } diff --git a/log.h b/log.h index ac7ae40..bb83622 100644 --- a/log.h +++ b/log.h @@ -47,27 +47,44 @@ void log_dbg_mode(int); extern logger_t *connect_log; #define log_connect_printf(fmt, ...) \ - logger_printf(connect_log, -1, (fmt), __VA_ARGS__) + logger_printf(connect_log, NULL, 0, (fmt), __VA_ARGS__) #define log_connect_print(s) \ - logger_print(connect_log, -1, (s)) + logger_print(connect_log, NULL, 0, (s)) #define log_connect_write(buf, sz) \ - logger_write(connect_log, -1, (buf), (sz)) + logger_write(connect_log, NULL, 0, (buf), (sz)) #define log_connect_print_free(s) \ - logger_print_freebuf(connect_log, -1, (s)) + logger_print_freebuf(connect_log, NULL, 0, (s)) #define log_connect_write_free(buf, sz) \ - logger_write_freebuf(connect_log, -1, (buf), (sz)) + logger_write_freebuf(connect_log, NULL, 0, (buf), (sz)) -typedef struct log_content_ctx { - int open; - char *basedir; +/* per-connection ctx struct for content logging */ +typedef struct log_content_ctx +#if 0 +{ + unsigned int open : 1; + + /* used by all content log types */ int fd; - char *header_in; - char *header_out; -} log_content_ctx_t; -int log_content_open(log_content_ctx_t *, char *, char *, + /* content log type specific data */ + union { + struct { + char *header_in; + char *header_out; + } file; + struct { + char *filename; + } dir; + struct { + char *filename; + } spec; + } u; +} +#endif +log_content_ctx_t; +int log_content_open(log_content_ctx_t **, opts_t *, char *, char *, char *, char *, char *) NONNULL(1,2,3) WUNRES; void log_content_submit(log_content_ctx_t *, logbuf_t *, int) NONNULL(1,2); -void log_content_close(log_content_ctx_t *) NONNULL(1); +void log_content_close(log_content_ctx_t **) NONNULL(1); int log_preinit(opts_t *) NONNULL(1) WUNRES; int log_init(opts_t *) NONNULL(1) WUNRES; diff --git a/logbuf.c b/logbuf.c index 12c5cf9..ffdcc77 100644 --- a/logbuf.c +++ b/logbuf.c @@ -34,7 +34,8 @@ #include /* - * Dynamic log buffer with zero-copy chaining and fd meta information. + * Dynamic log buffer with zero-copy chaining, generic void * file handle + * and ctl for status control flags. * Logbuf always owns the internal allocated buffer. */ @@ -43,7 +44,7 @@ * The provided buffer will be freed by logbuf_free() if non-NULL. */ logbuf_t * -logbuf_new(void *buf, size_t sz, int fd, logbuf_t *next) +logbuf_new(void *buf, size_t sz, void *fh, logbuf_t *next) { logbuf_t *lb; @@ -51,7 +52,8 @@ logbuf_new(void *buf, size_t sz, int fd, logbuf_t *next) return NULL; lb->buf = buf; lb->sz = sz; - lb->fd = fd; + lb->fh = fh; + lb->ctl = 0; lb->next = next; return lb; } @@ -60,7 +62,7 @@ logbuf_new(void *buf, size_t sz, int fd, logbuf_t *next) * Create new logbuf, allocating sz bytes into the internal buffer. */ logbuf_t * -logbuf_new_alloc(size_t sz, int fd, logbuf_t *next) +logbuf_new_alloc(size_t sz, void *fh, logbuf_t *next) { logbuf_t *lb; @@ -71,7 +73,8 @@ logbuf_new_alloc(size_t sz, int fd, logbuf_t *next) return NULL; } lb->sz = sz; - lb->fd = fd; + lb->fh = fh; + lb->ctl = 0; lb->next = next; return lb; } @@ -80,7 +83,7 @@ logbuf_new_alloc(size_t sz, int fd, logbuf_t *next) * Create new logbuf, copying buf into a newly allocated internal buffer. */ logbuf_t * -logbuf_new_copy(const void *buf, size_t sz, int fd, logbuf_t *next) +logbuf_new_copy(const void *buf, size_t sz, void *fh, logbuf_t *next) { logbuf_t *lb; @@ -92,16 +95,17 @@ logbuf_new_copy(const void *buf, size_t sz, int fd, logbuf_t *next) } memcpy(lb->buf, buf, sz); lb->sz = sz; - lb->fd = fd; + lb->fh = fh; + lb->ctl = 0; lb->next = next; return lb; } /* - * Create new logbuf using printf, setting fd and next. + * Create new logbuf using printf, setting fh and next. */ logbuf_t * -logbuf_new_printf(int fd, logbuf_t *next, const char *fmt, ...) +logbuf_new_printf(void *fh, logbuf_t *next, const char *fmt, ...) { va_list ap; logbuf_t *lb; @@ -115,7 +119,8 @@ logbuf_new_printf(int fd, logbuf_t *next, const char *fmt, ...) free(lb); return NULL; } - lb->fd = fd; + lb->fh = fh; + lb->ctl = 0; lb->next = next; return lb; } @@ -145,13 +150,15 @@ logbuf_write_free(logbuf_t *lb, writefunc_t writefunc) { ssize_t rv1, rv2 = 0; - rv1 = writefunc(lb->fd, lb->buf, lb->sz); - free(lb->buf); + rv1 = writefunc(lb->fh, lb->buf, lb->sz); + if (lb->buf) { + free(lb->buf); + } if (lb->next) { if (rv1 == -1) { logbuf_free(lb->next); } else { - lb->next->fd = lb->fd; + lb->next->fh = lb->fh; rv2 = logbuf_write_free(lb->next, writefunc); } } diff --git a/logbuf.h b/logbuf.h index bc9e842..1455e83 100644 --- a/logbuf.h +++ b/logbuf.h @@ -37,21 +37,27 @@ typedef struct logbuf { unsigned char *buf; ssize_t sz; - int fd; + void *fh; + unsigned long ctl; struct logbuf *next; } logbuf_t; -typedef ssize_t (*writefunc_t)(int, const void *, size_t); +typedef ssize_t (*writefunc_t)(void *, const void *, size_t); -logbuf_t * logbuf_new(void *, size_t, int, logbuf_t *) MALLOC; -logbuf_t * logbuf_new_alloc(size_t, int, logbuf_t *) MALLOC; -logbuf_t * logbuf_new_copy(const void *, size_t, int, logbuf_t *) MALLOC; -logbuf_t * logbuf_new_printf(int, logbuf_t *, const char *, ...) +logbuf_t * logbuf_new(void *, size_t, void *, logbuf_t *) MALLOC; +logbuf_t * logbuf_new_alloc(size_t, void *, logbuf_t *) MALLOC; +logbuf_t * logbuf_new_copy(const void *, size_t, void *, logbuf_t *) MALLOC; +logbuf_t * logbuf_new_printf(void *, logbuf_t *, const char *, ...) MALLOC PRINTF(3,4); ssize_t logbuf_size(logbuf_t *) NONNULL(1) WUNRES; ssize_t logbuf_write_free(logbuf_t *, writefunc_t) NONNULL(1); void logbuf_free(logbuf_t *) NONNULL(1); +#define logbuf_ctl_clear(x) (x)->ctl = 0 +#define logbuf_ctl_set(x, y) (x)->ctl |= (y) +#define logbuf_ctl_unset(x, y) (x)->ctl &= ~(y) +#define logbuf_ctl_isset(x, y) (!!((x)->ctl & (y))) + #endif /* !LOGBUF_H */ /* vim: set noet ft=c: */ diff --git a/logger.c b/logger.c index b8ad5a0..3b4cb67 100644 --- a/logger.c +++ b/logger.c @@ -45,10 +45,16 @@ struct logger { pthread_t thr; + logger_open_func_t open; + logger_close_func_t close; + logger_prep_func_t prep; logger_write_func_t write; thrqueue_t *queue; }; +#define LBFLAG_OPEN 1 +#define LBFLAG_CLOSE 2 + static void logger_clear(logger_t *logger) { @@ -61,7 +67,8 @@ logger_clear(logger_t *logger) * not in the thread calling logger_submit(). */ logger_t * -logger_new(logger_write_func_t writefunc) +logger_new(logger_open_func_t openfunc, logger_close_func_t closefunc, + logger_write_func_t writefunc, logger_prep_func_t prepfunc) { logger_t *logger; @@ -69,7 +76,10 @@ logger_new(logger_write_func_t writefunc) if (!logger) return NULL; logger_clear(logger); + logger->open = openfunc; + logger->close = closefunc; logger->write = writefunc; + logger->prep = prepfunc; logger->queue = NULL; return logger; } @@ -88,12 +98,57 @@ logger_free(logger_t *logger) { /* * Submit a buffer to be logged by the logger thread. - * Buffer will be freed after logging completes. + * Calls the prep callback from within the calling tread before submission. + * Buffer will be freed after logging completes or on failure. * Returns -1 on error, 0 on success. */ int -logger_submit(logger_t *logger, logbuf_t *lb) +logger_submit(logger_t *logger, void *fh, unsigned long prepflags, + logbuf_t *lb) { + if (logger->prep) + lb = logger->prep(fh, prepflags, lb); + if (!lb) + return -1; + lb->fh = fh; + logbuf_ctl_clear(lb); + return thrqueue_enqueue(logger->queue, lb) ? 0 : -1; +} + +/* + * Submit a file open event to the logger thread. + * fh is the file handle; an opaque unique address identifying the new file. + * If no open callback is configured, returns successfully. + * Returns 0 on success, -1 on failure. + */ +int logger_open(logger_t *logger, void *fh) +{ + logbuf_t *lb; + + if (!logger->open) + return 0; + + lb = logbuf_new(NULL, 0, NULL, NULL); + lb->fh = fh; + logbuf_ctl_set(lb, LBFLAG_OPEN); + return thrqueue_enqueue(logger->queue, lb) ? 0 : -1; +} + +/* + * Submit a file close event to the logger thread. + * If no close callback is configured, returns successfully. + * Returns 0 on success, -1 on failure. + */ +int logger_close(logger_t *logger, void *fh) +{ + logbuf_t *lb; + + if (!logger->close) + return 0; + + lb = logbuf_new(NULL, 0, NULL, NULL); + lb->fh = fh; + logbuf_ctl_set(lb, LBFLAG_CLOSE); return thrqueue_enqueue(logger->queue, lb) ? 0 : -1; } @@ -107,7 +162,13 @@ logger_thread(void *arg) logbuf_t *lb; while ((lb = thrqueue_dequeue(logger->queue))) { - logbuf_write_free(lb, logger->write); + if (logbuf_ctl_isset(lb, LBFLAG_OPEN)) { + logger->open(lb->fh); + } else if (logbuf_ctl_isset(lb, LBFLAG_CLOSE)) { + logger->close(lb->fh); + } else { + logbuf_write_free(lb, logger->write); + } } return NULL; @@ -180,12 +241,13 @@ logger_stop(logger_t *logger) { * All of the functions return 0 on succes, -1 on failure. */ int -logger_printf(logger_t *logger, int fd, const char *fmt, ...) +logger_printf(logger_t *logger, void *fh, unsigned long prepflags, + const char *fmt, ...) { va_list ap; logbuf_t *lb; - lb = logbuf_new(NULL, 0, fd, NULL); + lb = logbuf_new(NULL, 0, fh, NULL); if (!lb) return -1; va_start(ap, fmt); @@ -195,43 +257,47 @@ logger_printf(logger_t *logger, int fd, const char *fmt, ...) logbuf_free(lb); return -1; } - return logger_submit(logger, lb); + return logger_submit(logger, fh, prepflags, lb); } int -logger_write(logger_t *logger, int fd, const void *buf, size_t sz) +logger_write(logger_t *logger, void *fh, unsigned long prepflags, + const void *buf, size_t sz) { logbuf_t *lb; - if (!(lb = logbuf_new_copy(buf, sz, fd, NULL))) + if (!(lb = logbuf_new_copy(buf, sz, fh, NULL))) return -1; - return logger_submit(logger, lb); + return logger_submit(logger, fh, prepflags, lb); } int -logger_print(logger_t *logger, int fd, const char *s) +logger_print(logger_t *logger, void *fh, unsigned long prepflags, + const char *s) { logbuf_t *lb; - if (!(lb = logbuf_new_copy(s, s ? strlen(s) : 0, fd, NULL))) + if (!(lb = logbuf_new_copy(s, s ? strlen(s) : 0, fh, NULL))) return -1; - return logger_submit(logger, lb); + return logger_submit(logger, fh, prepflags, lb); } int -logger_write_freebuf(logger_t *logger, int fd, void *buf, size_t sz) +logger_write_freebuf(logger_t *logger, void *fh, unsigned long prepflags, + void *buf, size_t sz) { logbuf_t *lb; - if (!(lb = logbuf_new(buf, sz, fd, NULL))) + if (!(lb = logbuf_new(buf, sz, fh, NULL))) return -1; - return logger_submit(logger, lb); + return logger_submit(logger, fh, prepflags, lb); } int -logger_print_freebuf(logger_t *logger, int fd, char *s) +logger_print_freebuf(logger_t *logger, void *fh, unsigned long prepflags, + char *s) { logbuf_t *lb; - if (!(lb = logbuf_new(s, s ? strlen(s) : 0, fd, NULL))) + if (!(lb = logbuf_new(s, s ? strlen(s) : 0, fh, NULL))) return -1; - return logger_submit(logger, lb); + return logger_submit(logger, fh, prepflags, lb); } /* vim: set noet ft=c: */ diff --git a/logger.h b/logger.h index a2ee998..93b394c 100644 --- a/logger.h +++ b/logger.h @@ -35,21 +35,34 @@ #include #include -typedef ssize_t (*logger_write_func_t)(int, const void *, size_t); +typedef int (*logger_open_func_t)(void *); +typedef void (*logger_close_func_t)(void *); +typedef ssize_t (*logger_write_func_t)(void *, const void *, size_t); +typedef logbuf_t * (*logger_prep_func_t)(void *, unsigned long, logbuf_t *); typedef struct logger logger_t; -logger_t * logger_new(logger_write_func_t) NONNULL(1) MALLOC; +logger_t * logger_new(logger_open_func_t, logger_close_func_t, + logger_write_func_t, logger_prep_func_t) + NONNULL(3) MALLOC; void logger_free(logger_t *) NONNULL(1); -int logger_start(logger_t *) NONNULL(1); +int logger_start(logger_t *) NONNULL(1) WUNRES; void logger_leave(logger_t *) NONNULL(1); -int logger_join(logger_t *) NONNULL(1); -int logger_stop(logger_t *) NONNULL(1); -int logger_submit(logger_t *, logbuf_t *) NONNULL(1); -int logger_printf(logger_t *, int, const char *, ...) PRINTF(3,4) NONNULL(1,3); -int logger_print(logger_t *, int, const char *) NONNULL(1); -int logger_write(logger_t *, int, const void *, size_t) NONNULL(1); -int logger_print_freebuf(logger_t *, int, char *) NONNULL(1); -int logger_write_freebuf(logger_t *, int, void *, size_t) NONNULL(1); +int logger_join(logger_t *) NONNULL(1) /*WUNRES*/; +int logger_stop(logger_t *) NONNULL(1) /*WUNRES*/; +int logger_open(logger_t *, void *) NONNULL(1,2) WUNRES; +int logger_close(logger_t *, void *) NONNULL(1,2) /*WUNRES*/; +int logger_submit(logger_t *, void *, unsigned long, + logbuf_t *) NONNULL(1,4) /*WUNRES*/; +int logger_printf(logger_t *, void *, unsigned long, + const char *, ...) PRINTF(4,5) NONNULL(1,4) /*WUNRES*/; +int logger_print(logger_t *, void *, unsigned long, + const char *) NONNULL(1,4) /*WUNRES*/; +int logger_write(logger_t *, void *, unsigned long, + const void *, size_t) NONNULL(1,4) /*WUNRES*/; +int logger_print_freebuf(logger_t *, void *, unsigned long, + char *) NONNULL(1,4) /*WUNRES*/; +int logger_write_freebuf(logger_t *, void *, unsigned long, + void *, size_t) NONNULL(1,4) /*WUNRES*/; #endif /* !LOGGER_H */ diff --git a/pxyconn.c b/pxyconn.c index 10dda12..33bb8ff 100644 --- a/pxyconn.c +++ b/pxyconn.c @@ -156,7 +156,7 @@ typedef struct pxy_conn_ctx { #endif /* HAVE_LOCAL_PROCINFO */ /* content log context */ - log_content_ctx_t logctx; + log_content_ctx_t *logctx; /* store fd and fd event while connected is 0 */ evutil_socket_t fd; @@ -1377,10 +1377,10 @@ deny: if (WANT_CONTENT_LOG(ctx)) { logbuf_t *lb; lb = logbuf_new_alloc(evbuffer_get_length(inbuf), - -1, NULL); + NULL, NULL); if (lb && (evbuffer_copyout(inbuf, lb->buf, lb->sz) != -1)) { - log_content_submit(&ctx->logctx, lb, 0); + log_content_submit(ctx->logctx, lb, 0); } } evbuffer_drain(inbuf, evbuffer_get_length(inbuf)); @@ -1391,9 +1391,10 @@ deny: ctx->ocsp_denied = 1; if (WANT_CONTENT_LOG(ctx)) { logbuf_t *lb; - lb = logbuf_new_copy(ocspresp, sizeof(ocspresp) - 1, -1, NULL); + lb = logbuf_new_copy(ocspresp, sizeof(ocspresp) - 1, + NULL, NULL); if (lb) { - log_content_submit(&ctx->logctx, lb, 1); + log_content_submit(ctx->logctx, lb, 1); } } } @@ -1455,7 +1456,7 @@ pxy_bev_readcb(struct bufferevent *bev, void *arg) char *replace; if (WANT_CONTENT_LOG(ctx)) { logbuf_t *tmp; - tmp = logbuf_new_printf(-1, NULL, + tmp = logbuf_new_printf(NULL, NULL, "%s\r\n", line); if (tail) { if (tmp) { @@ -1483,7 +1484,7 @@ pxy_bev_readcb(struct bufferevent *bev, void *arg) } } if (lb && WANT_CONTENT_LOG(ctx)) { - log_content_submit(&ctx->logctx, lb, 0); + log_content_submit(ctx->logctx, lb, 0); } if (!ctx->seen_req_header) return; @@ -1498,7 +1499,7 @@ pxy_bev_readcb(struct bufferevent *bev, void *arg) char *replace; if (WANT_CONTENT_LOG(ctx)) { logbuf_t *tmp; - tmp = logbuf_new_printf(-1, NULL, + tmp = logbuf_new_printf(NULL, NULL, "%s\r\n", line); if (tail) { if (tmp) { @@ -1526,7 +1527,7 @@ pxy_bev_readcb(struct bufferevent *bev, void *arg) } } if (lb && WANT_CONTENT_LOG(ctx)) { - log_content_submit(&ctx->logctx, lb, 0); + log_content_submit(ctx->logctx, lb, 0); } if (!ctx->seen_resp_header) return; @@ -1544,9 +1545,9 @@ pxy_bev_readcb(struct bufferevent *bev, void *arg) if (WANT_CONTENT_LOG(ctx)) { logbuf_t *lb; - lb = logbuf_new_alloc(evbuffer_get_length(inbuf), -1, NULL); + lb = logbuf_new_alloc(evbuffer_get_length(inbuf), NULL, NULL); if (lb && (evbuffer_copyout(inbuf, lb->buf, lb->sz) != -1)) { - log_content_submit(&ctx->logctx, lb, + log_content_submit(ctx->logctx, lb, (bev != ctx->src.bev)); } } @@ -1702,8 +1703,8 @@ pxy_bev_eventcb(struct bufferevent *bev, short events, void *arg) #endif /* HAVE_LOCAL_PROCINFO */ } if (WANT_CONTENT_LOG(ctx)) { - if (log_content_open(&ctx->logctx, ctx->src_str, - ctx->dst_str, + if (log_content_open(&ctx->logctx, ctx->opts, + ctx->src_str, ctx->dst_str, #ifdef HAVE_LOCAL_PROCINFO ctx->lproc.exec_path, ctx->lproc.user,