From 72157cf5eeaf352cabea6a1d0620aeede10f51d1 Mon Sep 17 00:00:00 2001 From: David Sheets Date: Sun, 20 Mar 2016 11:08:57 +0000 Subject: [PATCH] transfused: move logging off of the event actuation thread Signed-off-by: David Sheets --- alpine/packages/transfused/transfused.c | 28 +++++++------ alpine/packages/transfused/transfused.h | 3 ++ alpine/packages/transfused/transfused_log.c | 44 +++++++++++++++++++++ alpine/packages/transfused/transfused_log.h | 2 + 4 files changed, 66 insertions(+), 11 deletions(-) diff --git a/alpine/packages/transfused/transfused.c b/alpine/packages/transfused/transfused.c index 7fc4fcc1b..2445fdce0 100644 --- a/alpine/packages/transfused/transfused.c +++ b/alpine/packages/transfused/transfused.c @@ -511,7 +511,9 @@ void perform_syscall(connection_t * conn, uint8_t syscall, char path[]) { die(1, NULL, "Unknown event syscall %" PRIu8, syscall); } - if (r != 0) log_time(conn, "Event %s error: %s\n", name, strerror(errno)); + if (r != 0) + thread_log_time(conn, "Event %s %s error: %s\n", + name, path, strerror(errno)); } void * event_thread(void * connection_ptr) { @@ -525,6 +527,10 @@ void * event_thread(void * connection_ptr) { uint8_t syscall; void * msg; + // This thread registers with the mounted file system as being an + // fsnotify event actuator. Other mounted file system interactions + // (such as self-logging) SHOULD NOT occur on this thread. + write_pid(connection); if (asprintf(&read_path, "%s/connections/%ld/read", @@ -543,19 +549,20 @@ void * event_thread(void * connection_ptr) { event_len = (int) ntohs(*((uint16_t *) buf)); - if (debug) log_time(connection, "read %d bytes from connection %ld\n", - read_count, connection->id); + if (debug) + thread_log_time(connection, "read %d bytes from connection %ld\n", + read_count, connection->id); if (read_count != event_len) { - log_time(connection, "event thread: only read %d of %d\n", - read_count, event_len); + thread_log_time(connection, "event thread: only read %d of %d\n", + read_count, event_len); msg = must_malloc("event hex", read_count * 2 + 1); for (int i = 0; i < read_count; i++) { sprintf(((char *) msg) + (i * 2),"%02x",(int) (((char *) buf)[i])); } ((char *) msg)[read_count * 2] = 0; - log_time(connection, "message: %s\n", (char *) msg); + thread_log_time(connection, "message: %s\n", (char *) msg); free(msg); continue; @@ -730,7 +737,6 @@ void process_events(char * events_path, int events, parameters * params) { long conn_id; pthread_t child; connection_t * conn; - char * connection_type; void * (*connection_handler_thread)(void *); while (1) { @@ -766,11 +772,11 @@ void process_events(char * events_path, int events, parameters * params) { switch (buf[0]) { case 'm': - connection_type = "mount"; + conn->type_descr = "mount"; connection_handler_thread = mount_thread; break; case 'e': - connection_type = "event"; + conn->type_descr = "event"; connection_handler_thread = event_thread; break; default: @@ -780,11 +786,11 @@ void process_events(char * events_path, int events, parameters * params) { if ((errno = pthread_create(&child, NULL, connection_handler_thread, conn))) die(1, "", "Couldn't create thread for %s connection '%ld': ", - connection_type, conn_id); + conn->type_descr, conn_id); if ((errno = pthread_detach(child))) die(1, "", "Couldn't detach thread for %s connection '%ld': ", - connection_type, conn_id); + conn->type_descr, conn_id); if (debug) log_time(conn, "thread spawned\n"); } diff --git a/alpine/packages/transfused/transfused.h b/alpine/packages/transfused/transfused.h index 56383b14e..ed41fe416 100644 --- a/alpine/packages/transfused/transfused.h +++ b/alpine/packages/transfused/transfused.h @@ -15,8 +15,11 @@ typedef struct { typedef struct { parameters * params; long id; + char * type_descr; } connection_t; +void * must_malloc(char *const descr, size_t size); + void lock(char *const descr, pthread_mutex_t * mutex); void unlock(char *const descr, pthread_mutex_t * mutex); diff --git a/alpine/packages/transfused/transfused_log.c b/alpine/packages/transfused/transfused_log.c index 4d8375a15..2746453c5 100644 --- a/alpine/packages/transfused/transfused_log.c +++ b/alpine/packages/transfused/transfused_log.c @@ -94,6 +94,50 @@ void log_time(connection_t * connection, const char * fmt, ...) { va_end(args); } +typedef struct { + connection_t * connection; + char * msg; +} log_thread_state; + +void * log_time_thread(void * log_state_ptr) { + log_thread_state * log_state = log_state_ptr; + + log_time(log_state->connection, log_state->msg); + + free(log_state->msg); + free(log_state); + + return NULL; +} + +void thread_log_time(connection_t * conn, const char * fmt, ...) { + pthread_t logger; + va_list args; + log_thread_state * log_state; + + log_state = must_malloc("thread_log_time log_state", + sizeof(log_thread_state)); + log_state->connection = conn; + + va_start(args, fmt); + if (vasprintf(&log_state->msg, fmt, args) == -1) + die(1, "Couldn't allocate thread_log_time message", ""); + va_end(args); + + // TODO: We currently spawn a new thread for every message. This is + // far from ideal but fine for now as we anticipate thread-sensitive + // log demand to be low. + + if ((errno = pthread_create(&logger, NULL, log_time_thread, log_state))) + die(1, "", "Couldn't create log thread for %s connection '%ld': ", + conn->type_descr, conn->id); + + if ((errno = pthread_detach(logger))) + die(1, "", "Couldn't detach thread for %s connection '%ld': ", + conn->type_descr, conn->id); + +} + void log_continue_locked(connection_t * connection, const char * fmt, ...) { va_list args; diff --git a/alpine/packages/transfused/transfused_log.h b/alpine/packages/transfused/transfused_log.h index ed8f4d4c2..95af5b869 100644 --- a/alpine/packages/transfused/transfused_log.h +++ b/alpine/packages/transfused/transfused_log.h @@ -10,6 +10,8 @@ void log_time_locked(connection_t * connection, const char * fmt, ...); void log_time(connection_t * connection, const char * fmt, ...); +void thread_log_time(connection_t * connection, const char * fmt, ...); + void log_continue_locked(connection_t * connection, const char * fmt, ...); void log_continue(connection_t * connection, const char * fmt, ...);