transfused: push log messages over control channel if available

Also, remove self-logging and triggers.

Signed-off-by: David Sheets <dsheets@docker.com>
This commit is contained in:
David Sheets 2016-04-15 17:11:38 +01:00
parent 5910d4870d
commit fe91be997d
6 changed files with 259 additions and 214 deletions

View File

@ -27,9 +27,7 @@ start()
--pidfile ${PIDFILE} \ --pidfile ${PIDFILE} \
-- \ -- \
-p "${PIDFILE}" \ -p "${PIDFILE}" \
-l "${STARTUP_LOGFILE}" \ -l "${STARTUP_LOGFILE}"
-m "${MOUNT_TRIGGER}" \
-t "${RUNTIME_LOGFILE}"
eend $? "Failed to start transfused" eend $? "Failed to start transfused"
} }

View File

@ -44,22 +44,20 @@ char * default_socket = DEFAULT_SOCKET;
char * default_server = DEFAULT_SERVER; char * default_server = DEFAULT_SERVER;
char * usage = char * usage =
"usage: transfused [-p pidfile] [-d server] [-s socket] [-f fusermount]\n" "usage: transfused [-p pidfile] [-d server] [-s socket] [-f fusermount]\n"
" [-l logfile] [-m mount_trigger] [-t triggerlog]\n" " [-l logfile]\n"
" -p pidfile\tthe path at which to write the pid of the process\n" " -p pidfile\tthe path at which to write the pid of the process\n"
" -d " DEFAULT_SERVER "\tthe server address to use ('v:addr:port')\n" " -d " DEFAULT_SERVER "\tthe server address to use ('v:addr:port')\n"
" -s " DEFAULT_SOCKET "\tthe socket address to use ('v:addr:port')\n" " -s " DEFAULT_SOCKET "\tthe socket address to use ('v:addr:port')\n"
" -f " DEFAULT_FUSERMOUNT "\tthe fusermount executable to use\n" " -f " DEFAULT_FUSERMOUNT "\tthe fusermount executable to use\n"
" -l logfile\tthe log file to use before the mount trigger\n" " -l logfile\tthe log file to use before uplink\n"
" -m mount_trigger\tthe mountpoint to use to trigger log switchover\n" ;
" -t triggerlog\tthe file to use after the trigger\n";
int debug = 0; int debug = 0;
pthread_attr_t detached; pthread_attr_t detached;
typedef struct { typedef struct {
char * descr; connection_t * connection;
char * tag;
int from; int from;
int to; int to;
} copy_thread_state; } copy_thread_state;
@ -74,7 +72,7 @@ void * must_malloc(char *const descr, size_t size) {
void * ptr; void * ptr;
ptr = malloc(size); ptr = malloc(size);
if (size != 0 && ptr == NULL) die(1, descr, ""); if (size != 0 && ptr == NULL) die(1, NULL, descr, "");
return ptr; return ptr;
} }
@ -82,39 +80,40 @@ void * must_malloc(char *const descr, size_t size) {
void cond_init(char *const descr, pthread_cond_t * cond, void cond_init(char *const descr, pthread_cond_t * cond,
const pthread_condattr_t *restrict attr) { const pthread_condattr_t *restrict attr) {
if ((errno = pthread_cond_init(cond, attr))) if ((errno = pthread_cond_init(cond, attr)))
die(1, "", "cond init %s: ", descr); die(1, NULL, "", "cond init %s: ", descr);
} }
void lock_init(char *const descr, pthread_mutex_t * mutex, void lock_init(char *const descr, pthread_mutex_t * mutex,
const pthread_mutexattr_t *restrict attr) { const pthread_mutexattr_t *restrict attr) {
if ((errno = pthread_mutex_init(mutex, attr))) if ((errno = pthread_mutex_init(mutex, attr)))
die(1, "", "lock init %s: ", descr); die(1, NULL, "", "lock init %s: ", descr);
} }
void lock(char *const descr, pthread_mutex_t * mutex) { void lock(char *const descr, pthread_mutex_t * mutex) {
if ((errno = pthread_mutex_lock(mutex))) if ((errno = pthread_mutex_lock(mutex)))
die(1, "", "lock %s: ", descr); die(1, NULL, "", "lock %s: ", descr);
} }
void unlock(char *const descr, pthread_mutex_t * mutex) { void unlock(char *const descr, pthread_mutex_t * mutex) {
if ((errno = pthread_mutex_unlock(mutex))) if ((errno = pthread_mutex_unlock(mutex)))
die(1, "", "unlock %s: ", descr); die(1, NULL, "", "unlock %s: ", descr);
} }
int bind_socket(const char * socket) { int bind_socket(const char * socket) {
int sock; int sock;
if (socket[0] == 0) if (socket[0] == 0)
die(2, NULL, "Socket family required"); die(2, NULL, NULL, "Socket family required");
if (socket[1] != ':') if (socket[1] != ':')
die(2, NULL, "Socket address required"); die(2, NULL, NULL, "Socket address required");
switch (socket[0]) { switch (socket[0]) {
case 'v': case 'v':
sock = bind_vsock(socket + 2); sock = bind_vsock(socket + 2);
break; break;
default: default:
die(2, NULL, "Unknown socket family '%c'", socket[0]); die(2, NULL, NULL, "Unknown socket family '%c'", socket[0]);
} }
return sock; return sock;
@ -124,30 +123,30 @@ int connect_socket(const char * socket) {
int sock; int sock;
if (socket[0] == 0) if (socket[0] == 0)
die(2, NULL, "Socket family required"); die(2, NULL, NULL, "Socket family required");
if (socket[1] != ':') if (socket[1] != ':')
die(2, NULL, "Scoket address required"); die(2, NULL, NULL, "Scoket address required");
switch (socket[0]) { switch (socket[0]) {
case 'v': case 'v':
sock = connect_vsock(socket + 2); sock = connect_vsock(socket + 2);
break; break;
default: default:
die(2, NULL, "Unknown socket family '%c'", socket[0]); die(2, NULL, NULL, "Unknown socket family '%c'", socket[0]);
} }
return sock; return sock;
} }
char ** read_opts(connection_t * connection, char * buf) { char ** read_opts(connection_t * conn, char * buf) {
int read_count; int read_count;
int optc = 1; int optc = 1;
char ** optv; char ** optv;
size_t mount_len; size_t mount_len;
// TODO: deal with socket read conditions e.g. EAGAIN // TODO: deal with socket read conditions e.g. EAGAIN
read_count = read(connection->sock, buf, EVENT_BUFSZ - 1); read_count = read(conn->sock, buf, EVENT_BUFSZ - 1);
if (read_count < 0) die(1, "read_opts error reading", ""); if (read_count < 0) die(1, conn->params, "read_opts error reading", "");
// TODO: protocol should deal with short read // TODO: protocol should deal with short read
buf[read_count] = 0x0; buf[read_count] = 0x0;
@ -169,9 +168,9 @@ char ** read_opts(connection_t * connection, char * buf) {
} }
mount_len = strnlen(optv[optc - 1], 4096) + 1; mount_len = strnlen(optv[optc - 1], 4096) + 1;
connection->mount_point = must_malloc("mount point string", mount_len); conn->mount_point = must_malloc("mount point string", mount_len);
strncpy(connection->mount_point, optv[optc - 1], mount_len - 1); strncpy(conn->mount_point, optv[optc - 1], mount_len - 1);
connection->mount_point[mount_len - 1] = '\0'; conn->mount_point[mount_len - 1] = '\0';
return optv; return optv;
} }
@ -180,7 +179,9 @@ uint64_t message_id(uint64_t * message) {
return message[1]; return message[1];
} }
int read_message(char * descr, int fd, char * buf, size_t max_read) { int read_message
(char * descr, parameters * params, int fd, char * buf, size_t max_read)
{
int read_count; int read_count;
size_t nbyte; size_t nbyte;
uint32_t len; uint32_t len;
@ -188,13 +189,15 @@ int read_message(char * descr, int fd, char * buf, size_t max_read) {
// TODO: socket read conditions e.g. EAGAIN // TODO: socket read conditions e.g. EAGAIN
read_count = read(fd, buf, 4); read_count = read(fd, buf, 4);
if (read_count != 4) { if (read_count != 4) {
if (read_count < 0) die(1, "", "read %s: error reading: ", descr); if (read_count < 0)
if (read_count == 0) die(1, NULL, "read %s: EOF reading length", descr); die(1, params, "", "read %s: error reading: ", descr);
die(1, NULL, "read %s: short read length %d", descr, read_count); if (read_count == 0)
die(1, params, NULL, "read %s: EOF reading length", descr);
die(1, params, NULL, "read %s: short read length %d", descr, read_count);
} }
len = *((uint32_t *) buf); len = *((uint32_t *) buf);
if (len > max_read) if (len > max_read)
die(1, NULL, "read %s: message size %d exceeds buffer capacity %d", die(1, params, NULL, "read %s: message size %d exceeds buffer capacity %d",
len, max_read); len, max_read);
nbyte = (size_t) (len - 4); nbyte = (size_t) (len - 4);
@ -203,8 +206,8 @@ int read_message(char * descr, int fd, char * buf, size_t max_read) {
do { do {
// TODO: socket read conditions e.g. EAGAIN // TODO: socket read conditions e.g. EAGAIN
read_count = read(fd, buf, nbyte); read_count = read(fd, buf, nbyte);
if (read_count < 0) die(1, "", "read %s: error reading: ", descr); if (read_count < 0) die(1, params, "", "read %s: error reading: ", descr);
if (read_count == 0) die(1, NULL, "read %s: EOF reading", descr); if (read_count == 0) die(1, params, NULL, "read %s: EOF reading", descr);
nbyte -= read_count; nbyte -= read_count;
buf += read_count; buf += read_count;
} while (nbyte != 0); } while (nbyte != 0);
@ -215,35 +218,37 @@ int read_message(char * descr, int fd, char * buf, size_t max_read) {
void copy_into_fuse(copy_thread_state * copy_state) { void copy_into_fuse(copy_thread_state * copy_state) {
int from = copy_state->from; int from = copy_state->from;
int to = copy_state->to; int to = copy_state->to;
char * descr = copy_state->descr; char * descr = copy_state->connection->mount_point;
int read_count, write_count; int read_count, write_count;
void * buf; void * buf;
parameters * params = copy_state->connection->params;
buf = must_malloc(descr, IN_BUFSZ); buf = must_malloc(descr, IN_BUFSZ);
while(1) { while(1) {
read_count = read_message(descr, from, (char *) buf, IN_BUFSZ); read_count = read_message(descr, params, from, (char *) buf, IN_BUFSZ);
write_count = write(to, buf, read_count); write_count = write(to, buf, read_count);
if (write_count < 0) die(1, "", "copy %s: error writing: ", descr); if (write_count < 0) die(1, params, "", "copy %s: error writing: ", descr);
// /dev/fuse accepts only complete writes // /dev/fuse accepts only complete writes
if (write_count != read_count) if (write_count != read_count)
die(1, NULL, "copy %s: read %d but only wrote %d", die(1, params, NULL, "copy %s: read %d but only wrote %d",
descr, read_count, write_count); descr, read_count, write_count);
} }
free(buf); free(buf);
} }
void write_exactly(char * descr, int fd, char * buf, size_t nbyte) { void write_exactly(char * descr, int fd, void * p, size_t nbyte) {
int write_count; int write_count;
char * buf = p;
do { do {
// TODO: socket write conditions e.g. EAGAIN // TODO: socket write conditions e.g. EAGAIN
write_count = write(fd, buf, nbyte); write_count = write(fd, buf, nbyte);
if (write_count < 0) die(1, "", "copy %s: error writing: ", descr); if (write_count < 0) die(1, NULL, "", "%s: error writing: ", descr);
if (write_count == 0) die(1, "", "copy %s: 0 write: ", descr); if (write_count == 0) die(1, NULL, "", "%s: 0 write: ", descr);
nbyte -= write_count; nbyte -= write_count;
buf += write_count; buf += write_count;
@ -253,16 +258,17 @@ void write_exactly(char * descr, int fd, char * buf, size_t nbyte) {
void copy_outof_fuse(copy_thread_state * copy_state) { void copy_outof_fuse(copy_thread_state * copy_state) {
int from = copy_state->from; int from = copy_state->from;
int to = copy_state->to; int to = copy_state->to;
char * descr = copy_state->descr; char * descr = copy_state->connection->mount_point;
int read_count; int read_count;
void * buf; void * buf;
parameters * params = copy_state->connection->params;
buf = must_malloc(descr, OUT_BUFSZ); buf = must_malloc(descr, OUT_BUFSZ);
while(1) { while(1) {
// /dev/fuse only returns complete reads // /dev/fuse only returns complete reads
read_count = read(from, buf, OUT_BUFSZ); read_count = read(from, buf, OUT_BUFSZ);
if (read_count < 0) die(1, "", "copy %s: error reading: ", descr); if (read_count < 0) die(1, params, "", "copy %s: error reading: ", descr);
write_exactly(descr, to, (char *) buf, read_count); write_exactly(descr, to, (char *) buf, read_count);
} }
@ -275,7 +281,6 @@ void * copy_clean_into_fuse(copy_thread_state * copy_state) {
close(copy_state->from); close(copy_state->from);
free(copy_state->descr);
free(copy_state); free(copy_state);
return NULL; return NULL;
@ -290,7 +295,6 @@ void * copy_clean_outof_fuse(copy_thread_state * copy_state) {
close(copy_state->to); close(copy_state->to);
free(copy_state->descr);
free(copy_state); free(copy_state);
return NULL; return NULL;
@ -300,7 +304,7 @@ void * copy_clean_outof_fuse_thread(void * copy_state) {
return (copy_clean_outof_fuse((copy_thread_state *) copy_state)); return (copy_clean_outof_fuse((copy_thread_state *) copy_state));
} }
int recv_fd(int sock) { int recv_fd(parameters * params, int sock) {
int ret; int ret;
int fd = -1; int fd = -1;
char iochar; char iochar;
@ -323,7 +327,7 @@ int recv_fd(int sock) {
ret = recvmsg(sock, &msg, 0); ret = recvmsg(sock, &msg, 0);
if (ret == -1) die(1, "recvmsg", ""); if (ret == -1) die(1, params, "recvmsg", "");
if (ret > 0 && msg.msg_controllen > 0) { if (ret > 0 && msg.msg_controllen > 0) {
cmsg = CMSG_FIRSTHDR(&msg); cmsg = CMSG_FIRSTHDR(&msg);
@ -350,19 +354,20 @@ int get_fuse_sock(connection_t * conn, int optc, char *const optv[]) {
argv[0] = conn->params->fusermount; argv[0] = conn->params->fusermount;
memcpy(&argv[1], optv, (optc + 1) * sizeof(char *)); memcpy(&argv[1], optv, (optc + 1) * sizeof(char *));
lock("get_fuse_sock fd_lock", &conn->params->fd_lock); lock("get_fuse_sock ctl_lock", &conn->params->ctl_lock);
log_time_locked(conn,"mount "); log_time_locked(conn->params, "mount ");
for (int i = 0; argv[i]; i++) log_continue_locked(conn, "%s ",argv[i]); for (int i = 0; argv[i]; i++)
log_continue_locked(conn, "\n"); log_continue_locked(conn->params, "%s ",argv[i]);
unlock("get_fuse_sock fd_lock", &conn->params->fd_lock); log_continue_locked(conn->params, "\n");
unlock("get_fuse_sock ctl_lock", &conn->params->ctl_lock);
// make the socket over which we'll be sent the FUSE socket fd // make the socket over which we'll be sent the FUSE socket fd
if (socketpair(PF_UNIX, SOCK_STREAM, 0, fuse_socks)) if (socketpair(PF_UNIX, SOCK_STREAM, 0, fuse_socks))
die(1, "Couldn't create FUSE socketpair", ""); die(1, conn->params, "Couldn't create FUSE socketpair", "");
// prepare to exec the suid binary fusermount // prepare to exec the suid binary fusermount
if (asprintf(&envp[0], "_FUSE_COMMFD=%d", fuse_socks[0]) == -1) if (asprintf(&envp[0], "_FUSE_COMMFD=%d", fuse_socks[0]) == -1)
die(1, "Couldn't allocate fusermount envp", ""); die(1, conn->params, "Couldn't allocate fusermount envp", "");
envp[1] = 0x0; envp[1] = 0x0;
@ -370,7 +375,7 @@ int get_fuse_sock(connection_t * conn, int optc, char *const optv[]) {
fusermount_pid = fork(); fusermount_pid = fork();
if (!fusermount_pid) // child if (!fusermount_pid) // child
if (execve(argv[0], argv, envp)) if (execve(argv[0], argv, envp))
die(1, "Failed to execute fusermount", ""); die(1, conn->params, "Failed to execute fusermount", "");
// parent // parent
free(argv); free(argv);
@ -382,16 +387,17 @@ int get_fuse_sock(connection_t * conn, int optc, char *const optv[]) {
// wait for fusermount to return // wait for fusermount to return
waitpid(fusermount_pid, &status, 0); waitpid(fusermount_pid, &status, 0);
if (!WIFEXITED(status)) if (!WIFEXITED(status))
die(1, NULL, "fusermount terminated abnormally"); die(1, conn->params, NULL, "fusermount terminated abnormally");
if (WEXITSTATUS(status)) if (WEXITSTATUS(status))
die(1, NULL, "fusermount exited with code %d", WEXITSTATUS(status)); die(1, conn->params, NULL,
"fusermount exited with code %d", WEXITSTATUS(status));
if (debug) log_time(conn, "about to recv_fd from fusermount\n"); if (debug) log_time(conn->params, "about to recv_fd from fusermount\n");
fd = recv_fd(fuse_socks[1]); fd = recv_fd(conn->params, fuse_socks[1]);
if (fd == -1) if (fd == -1)
die(1, NULL, "Couldn't receive fd over FUSE socket"); die(1, conn->params, NULL, "Couldn't receive fd over FUSE socket");
// close the read end of the socket // close the read end of the socket
close(fuse_socks[1]); close(fuse_socks[1]);
@ -405,13 +411,13 @@ void start_reader(connection_t * connection, int fuse) {
copy_state = (copy_thread_state *) must_malloc("start_reader copy_state", copy_state = (copy_thread_state *) must_malloc("start_reader copy_state",
sizeof(copy_thread_state)); sizeof(copy_thread_state));
copy_state->descr = connection->mount_point; copy_state->connection = connection;
copy_state->tag = "read";
copy_state->from = connection->sock; copy_state->from = connection->sock;
copy_state->to = fuse; copy_state->to = fuse;
if ((errno = pthread_create(&child, &detached, if ((errno = pthread_create(&child, &detached,
copy_clean_into_fuse_thread, copy_state))) copy_clean_into_fuse_thread, copy_state)))
die(1, "", "couldn't create read copy thread for mount %s: ", die(1, connection->params, "",
"couldn't create read copy thread for mount %s: ",
connection->mount_point); connection->mount_point);
} }
@ -421,13 +427,13 @@ void start_writer(connection_t * connection, int fuse) {
copy_state = (copy_thread_state *) must_malloc("do_write copy_state", copy_state = (copy_thread_state *) must_malloc("do_write copy_state",
sizeof(copy_thread_state)); sizeof(copy_thread_state));
copy_state->descr = connection->mount_point; copy_state->connection = connection;
copy_state->tag = "write";
copy_state->from = fuse; copy_state->from = fuse;
copy_state->to = connection->sock; copy_state->to = connection->sock;
if ((errno = pthread_create(&child, &detached, if ((errno = pthread_create(&child, &detached,
copy_clean_outof_fuse_thread, copy_state))) copy_clean_outof_fuse_thread, copy_state)))
die(1, "", "Couldn't create write copy thread for mount %s: ", die(1, connection->params, "",
"Couldn't create write copy thread for mount %s: ",
connection->mount_point); connection->mount_point);
} }
@ -448,6 +454,7 @@ void * mount_connection(connection_t * conn) {
fuse = get_fuse_sock(conn, optc, optv); fuse = get_fuse_sock(conn, optc, optv);
free(buf); free(buf);
free(optv);
lock_init("copy_lock", &copy_lock, NULL); lock_init("copy_lock", &copy_lock, NULL);
cond_init("copy_halt", &copy_halt, NULL); cond_init("copy_halt", &copy_halt, NULL);
@ -455,29 +462,11 @@ void * mount_connection(connection_t * conn) {
start_reader(conn, fuse); start_reader(conn, fuse);
start_writer(conn, fuse); start_writer(conn, fuse);
// trigger?
// TODO: strcmp scares me
// TODO: append logfile to trigger_log
if (conn->params->mount_trigger != NULL
&& conn->params->trigger_log != NULL
&& 0 == strcmp(optv[optc - 1], conn->params->mount_trigger)) {
lock("trigger mount fd_lock", &conn->params->fd_lock);
log_time_locked(conn, "Log mount trigger fired on %s, logging to %s\n",
conn->params->mount_trigger, conn->params->trigger_log);
conn->params->trigger_fd = open(conn->params->trigger_log,
O_WRONLY | O_APPEND | O_CREAT, 0600);
if (conn->params->trigger_fd == -1)
die(1, "", "Couldn't open trigger log %s: ", conn->params->trigger_log);
unlock("trigger mount fd_lock", &conn->params->fd_lock);
}
free(optv);
lock("copy lock", &copy_lock); lock("copy lock", &copy_lock);
while (!should_halt) while (!should_halt)
if ((errno = pthread_cond_wait(&copy_halt, &copy_lock))) if ((errno = pthread_cond_wait(&copy_halt, &copy_lock)))
die(1, "", "Couldn't wait for copy halt for mount %s: ", die(1, conn->params, "",
"Couldn't wait for copy halt for mount %s: ",
conn->mount_point); conn->mount_point);
unlock("copy lock", &copy_lock); unlock("copy lock", &copy_lock);
@ -496,18 +485,19 @@ void write_pid(connection_t * connection) {
int pid_s_len, write_count; int pid_s_len, write_count;
if (asprintf(&pid_s, "%lld", (long long) pid) == -1) if (asprintf(&pid_s, "%lld", (long long) pid) == -1)
die(1, "Couldn't allocate pid string", ""); die(1, connection->params, "Couldn't allocate pid string", "");
pid_s_len = strlen(pid_s); pid_s_len = strlen(pid_s);
// TODO: check for socket write conditions e.g. EAGAIN // TODO: check for socket write conditions e.g. EAGAIN
write_count = write(connection->sock, pid_s, pid_s_len); write_count = write(connection->sock, pid_s, pid_s_len);
if (write_count < 0) if (write_count < 0)
die(1, "Error writing pid", ""); die(1, connection->params, "Error writing pid", "");
// TODO: handle short writes // TODO: handle short writes
if (write_count != pid_s_len) if (write_count != pid_s_len)
die(1, NULL, "Error writing pid %s to socket: only wrote %d bytes", die(1, connection->params, NULL,
"Error writing pid %s to socket: only wrote %d bytes",
pid_s, write_count); pid_s, write_count);
free(pid_s); free(pid_s);
@ -550,7 +540,7 @@ void perform_syscall(connection_t * conn, uint8_t syscall, char path[]) {
break; break;
default: default:
die(1, NULL, "Unknown event syscall %" PRIu8, syscall); die(1, conn->params, NULL, "Unknown event syscall %" PRIu8, syscall);
} }
if (r != 0) if (r != 0)
@ -575,7 +565,8 @@ void * event_thread(void * connection_ptr) {
buf = must_malloc("incoming event buffer", EVENT_BUFSZ); buf = must_malloc("incoming event buffer", EVENT_BUFSZ);
while(1) { while(1) {
read_count = read_message("events", connection->sock, buf, EVENT_BUFSZ); read_count = read_message("events", connection->params,
connection->sock, buf, EVENT_BUFSZ);
if (debug) if (debug)
thread_log_time(connection, "read %d bytes from event connection\n", thread_log_time(connection, "read %d bytes from event connection\n",
@ -596,28 +587,29 @@ void * event_thread(void * connection_ptr) {
return NULL; return NULL;
} }
void write_pidfile(char * pidfile) { void write_pidfile(parameters * params) {
int fd; int fd;
pid_t pid = getpid(); pid_t pid = getpid();
char * pid_s; char * pid_s;
int pid_s_len, write_count; int pid_s_len, write_count;
if (asprintf(&pid_s, "%lld", (long long) pid) == -1) if (asprintf(&pid_s, "%lld", (long long) pid) == -1)
die(1, "Couldn't allocate pidfile string", ""); die(1, params, "Couldn't allocate pidfile string", "");
pid_s_len = strlen(pid_s); pid_s_len = strlen(pid_s);
fd = open(pidfile, O_WRONLY | O_CREAT | O_TRUNC, 0644); fd = open(params->pidfile, O_WRONLY | O_CREAT | O_TRUNC, 0644);
if (fd == -1) if (fd == -1)
die(1, "", "Couldn't open pidfile path %s: ", pidfile); die(1, params, "", "Couldn't open pidfile path %s: ", params->pidfile);
write_count = write(fd, pid_s, pid_s_len); write_count = write(fd, pid_s, pid_s_len);
if (write_count == -1) if (write_count == -1)
die(1, "", "Error writing pidfile %s: ", pidfile); die(1, params, "", "Error writing pidfile %s: ", params->pidfile);
if (write_count != pid_s_len) if (write_count != pid_s_len)
die(1, NULL, "Error writing %s to pidfile %s: only wrote %d bytes", die(1, params, NULL,
pid_s, pidfile, write_count); "Error writing %s to pidfile %s: only wrote %d bytes",
pid_s, params->pidfile, write_count);
close(fd); close(fd);
free(pid_s); free(pid_s);
@ -625,31 +617,32 @@ void write_pidfile(char * pidfile) {
void * init_thread(void * params_ptr) { void * init_thread(void * params_ptr) {
parameters * params = params_ptr; parameters * params = params_ptr;
int init_sock = connect_socket(params->server);
int write_count, read_count; int write_count, read_count;
char init_msg[6] = { '\6', '\0', '\0', '\0', '\0', '\0' }; char init_msg[6] = { '\6', '\0', '\0', '\0', '\0', '\0' };
void * buf; void * buf;
params->ctl_sock = connect_socket(params->server);
// TODO: handle short write/socket conditions // TODO: handle short write/socket conditions
write_count = write(init_sock, init_msg, sizeof(init_msg)); write_count = write(params->ctl_sock, init_msg, sizeof(init_msg));
if (write_count < 0) die(1, "init thread: couldn't write init", ""); if (write_count < 0) die(1, NULL, "init thread: couldn't write init", "");
if (write_count != sizeof(init_msg)) if (write_count != sizeof(init_msg))
die(1, "init thread: incomplete write", ""); die(1, NULL, "init thread: incomplete write", "");
buf = must_malloc("incoming init buffer", EVENT_BUFSZ); buf = must_malloc("incoming init buffer", EVENT_BUFSZ);
// TODO: handle short read/socket conditions // TODO: handle short read/socket conditions
read_count = read(init_sock, buf, EVENT_BUFSZ); read_count = read(params->ctl_sock, buf, EVENT_BUFSZ);
if (read_count < 0) die(1, "init thread: error reading", ""); if (read_count < 0) die(1, params, "init thread: error reading", "");
// TODO: handle other messages // TODO: handle other messages
if (read_count != 6) die(1, "init thread: response not 6", ""); if (read_count != 6) die(1, params, "init thread: response not 6", "");
for (int i = 0; i < sizeof(init_msg); i++) for (int i = 0; i < sizeof(init_msg); i++)
if (((char *)buf)[i] != init_msg[i]) if (((char *)buf)[i] != init_msg[i])
die(1, "init thread: unexpected message", ""); die(1, params, "init thread: unexpected message", "");
// we've gotten Continue so write the pidfile // we've gotten Continue so write the pidfile
if (params->pidfile != NULL) if (params->pidfile != NULL)
write_pidfile(params->pidfile); write_pidfile(params);
// TODO: handle more messages // TODO: handle more messages
return NULL; return NULL;
@ -661,10 +654,10 @@ void toggle_debug(int sig) {
void setup_debug() { void setup_debug() {
if (SIG_ERR == signal(SIGHUP, toggle_debug)) if (SIG_ERR == signal(SIGHUP, toggle_debug))
die(1, "Couldn't set SIGHUP behavior", ""); die(1, NULL, "Couldn't set SIGHUP behavior", "");
if (siginterrupt(SIGHUP, 1)) if (siginterrupt(SIGHUP, 1))
die(1, "Couldn't set siginterrupt for SIGHUP", ""); die(1, NULL, "Couldn't set siginterrupt for SIGHUP", "");
} }
void parse_parameters(int argc, char * argv[], parameters * params) { void parse_parameters(int argc, char * argv[], parameters * params) {
@ -676,12 +669,11 @@ void parse_parameters(int argc, char * argv[], parameters * params) {
params->fusermount = NULL; params->fusermount = NULL;
params->logfile = NULL; params->logfile = NULL;
params->logfile_fd = 0; params->logfile_fd = 0;
params->mount_trigger = NULL; params->data_sock = 0;
params->trigger_log = NULL; params->ctl_sock = 0;
params->trigger_fd = 0; lock_init("ctl_lock", &params->ctl_lock, NULL);
lock_init("fd_lock", &params->fd_lock, NULL);
while ((c = getopt(argc, argv, ":p:d:s:f:l:m:t:")) != -1) { while ((c = getopt(argc, argv, ":p:d:s:f:l:")) != -1) {
switch(c) { switch(c) {
case 'p': case 'p':
@ -704,14 +696,6 @@ void parse_parameters(int argc, char * argv[], parameters * params) {
params->logfile = optarg; params->logfile = optarg;
break; break;
case 'm':
params->mount_trigger = optarg;
break;
case 't':
params->trigger_log = optarg;
break;
case ':': case ':':
fprintf(stderr, "Option -%c requires a path argument\n", optopt); fprintf(stderr, "Option -%c requires a path argument\n", optopt);
errflg++; errflg++;
@ -763,14 +747,6 @@ void parse_parameters(int argc, char * argv[], parameters * params) {
perror(""); perror("");
exit(2); exit(2);
} }
if (params->mount_trigger != NULL
&& access(params->mount_trigger, F_OK)) {
fprintf(stderr, "-m %s path to mount point must exist: ",
params->mount_trigger);
perror("");
exit(2);
}
} }
void serve(parameters * params) { void serve(parameters * params) {
@ -780,11 +756,11 @@ void serve(parameters * params) {
connection_t * conn; connection_t * conn;
void * (*connection_handler_thread)(void *); void * (*connection_handler_thread)(void *);
if (listen(params->sock, 16)) if (listen(params->data_sock, 16))
die(1, "listen", ""); die(1, NULL, "listen", "");
if ((errno = pthread_create(&child, &detached, init_thread, params))) if ((errno = pthread_create(&child, &detached, init_thread, params)))
die(1, "", "Couldn't create initialization thread: "); die(1, NULL, "", "Couldn't create initialization thread: ");
while (1) { while (1) {
conn = (connection_t *) must_malloc("connection state", conn = (connection_t *) must_malloc("connection state",
@ -792,14 +768,15 @@ void serve(parameters * params) {
conn->params = params; conn->params = params;
conn->mount_point = ""; conn->mount_point = "";
conn->sock = accept(params->sock, &conn->sa_client, &conn->socklen_client); conn->sock = accept(params->data_sock,
&conn->sa_client, &conn->socklen_client);
if (conn->sock < 0) if (conn->sock < 0)
die(1, "accept", ""); die(1, params, "accept", "");
// TODO: check for socket read conditions e.g. EAGAIN // TODO: check for socket read conditions e.g. EAGAIN
read_count = read(conn->sock, &subproto_selector, 1); read_count = read(conn->sock, &subproto_selector, 1);
if (read_count <= 0) if (read_count <= 0)
die(1, "read subprotocol selector", ""); die(1, params, "read subprotocol selector", "");
switch (subproto_selector) { switch (subproto_selector) {
case 'm': case 'm':
@ -811,15 +788,15 @@ void serve(parameters * params) {
connection_handler_thread = event_thread; connection_handler_thread = event_thread;
break; break;
default: default:
die(1, NULL, "Unknown subprotocol type '%c'", subproto_selector); die(1, params, NULL, "Unknown subprotocol type '%c'", subproto_selector);
} }
if ((errno = pthread_create(&child, &detached, if ((errno = pthread_create(&child, &detached,
connection_handler_thread, conn))) connection_handler_thread, conn)))
die(1, "", "Couldn't create thread for %s connection: ", die(1, params, "", "Couldn't create thread for %s connection: ",
conn->type_descr); conn->type_descr);
if (debug) log_time(conn, "thread spawned\n"); if (debug) log_time(conn->params, "thread spawned\n");
} }
} }
@ -830,7 +807,7 @@ int main(int argc, char * argv[]) {
core_limit.rlim_cur = RLIM_INFINITY; core_limit.rlim_cur = RLIM_INFINITY;
core_limit.rlim_max = RLIM_INFINITY; core_limit.rlim_max = RLIM_INFINITY;
if (setrlimit(RLIMIT_CORE, &core_limit)) if (setrlimit(RLIMIT_CORE, &core_limit))
die(1, "", "Couldn't set RLIMIT_CORE to RLIM_INFINITY"); die(1, NULL, "", "Couldn't set RLIMIT_CORE to RLIM_INFINITY");
openlog(argv[0], LOG_CONS | LOG_PERROR | LOG_NDELAY, LOG_DAEMON); openlog(argv[0], LOG_CONS | LOG_PERROR | LOG_NDELAY, LOG_DAEMON);
@ -839,15 +816,15 @@ int main(int argc, char * argv[]) {
if ((errno = pthread_attr_setdetachstate(&detached, if ((errno = pthread_attr_setdetachstate(&detached,
PTHREAD_CREATE_DETACHED))) PTHREAD_CREATE_DETACHED)))
die(1, "Couldn't set pthread detach state", ""); die(1, NULL, "Couldn't set pthread detach state", "");
if (params.logfile != NULL) { if (params.logfile != NULL) {
params.logfile_fd = open(params.logfile, O_WRONLY | O_APPEND | O_CREAT); params.logfile_fd = open(params.logfile, O_WRONLY | O_APPEND | O_CREAT);
if (params.logfile_fd == -1) if (params.logfile_fd == -1)
die(1, "", "Couldn't open log file %s: ", params.logfile); die(1, NULL, "", "Couldn't open log file %s: ", params.logfile);
} }
params.sock = bind_socket(params.socket); params.data_sock = bind_socket(params.socket);
serve(&params); serve(&params);
return 0; return 0;

View File

@ -7,12 +7,10 @@ typedef struct {
char * fusermount; char * fusermount;
char * pidfile; char * pidfile;
char * logfile; char * logfile;
char * mount_trigger;
char * trigger_log;
int sock;
pthread_mutex_t fd_lock;
int logfile_fd; int logfile_fd;
int trigger_fd; int ctl_sock;
int data_sock;
pthread_mutex_t ctl_lock;
} parameters; } parameters;
typedef struct { typedef struct {
@ -31,3 +29,5 @@ void * must_malloc(char *const descr, size_t size);
void lock(char *const descr, pthread_mutex_t * mutex); void lock(char *const descr, pthread_mutex_t * mutex);
void unlock(char *const descr, pthread_mutex_t * mutex); void unlock(char *const descr, pthread_mutex_t * mutex);
void write_exactly(char * descr, int fd, void * buf, size_t nbyte);

View File

@ -11,6 +11,7 @@
#include <sys/time.h> #include <sys/time.h>
#include <time.h> #include <time.h>
#include <math.h> #include <math.h>
#include <inttypes.h>
#include "transfused.h" #include "transfused.h"
@ -34,75 +35,141 @@ void log_timestamp(int fd) {
dprintf(fd, "%s.%03d ", timestamp, msec); dprintf(fd, "%s.%03d ", timestamp, msec);
} }
void die(int exit_code, const char * perror_arg, const char * fmt, ...) { void die
va_list argp; (int exit_code, parameters * params, const char * parg, const char * fmt, ...);
int in_errno = errno;
va_start(argp, fmt); void vlog_sock_locked(int fd, const char * fmt, va_list args) {
vsyslog(LOG_CRIT, fmt, argp); uint16_t log_err_type = 1;
va_end(argp); int rc, len;
if (perror_arg != NULL) { va_list targs;
if (*perror_arg != 0) char * fill;
syslog(LOG_CRIT, "%s: %s", perror_arg, strerror(in_errno));
else va_copy(targs, args);
syslog(LOG_CRIT, "%s", strerror(in_errno)); len = vsnprintf(NULL, 0, fmt, targs);
if (len < 0) die(1, NULL, NULL, "Couldn't log due to vsnprintf failure");
va_end(targs);
rc = len + 4 + 2; // 4 for length itself and 2 for message type
write_exactly("vlog_sock_locked", fd, (uint32_t *) &rc, sizeof(uint32_t));
write_exactly("vlog_sock_locked", fd, &log_err_type, sizeof(uint16_t));
va_copy(targs, args);
rc = vdprintf(fd, fmt, targs);
if (rc < 0) die(1, NULL, "Couldn't send log message with vdprintf", "");
va_end(targs);
if (rc < len) { // we didn't write the whole message :-(
rc = len - rc;
fill = (char *) calloc(rc, 1);
if (fill == NULL) die(1, NULL, "vlog_sock_locked fill", "");
write_exactly("vlog_sock_locked fill", fd, fill, rc);
} }
exit(exit_code);
} }
void vlog_locked(connection_t * conn, const char * fmt, va_list args) { void log_sock_locked(int fd, const char * fmt, ...) {
int fd = conn->params->trigger_fd;
if (fd != 0) {
vdprintf(fd, fmt, args);
} else {
vsyslog(LOG_INFO, fmt, args);
fd = conn->params->logfile_fd;
if (fd != 0) {
vdprintf(fd, fmt, args);
}
}
}
void vlog_time_locked(connection_t * conn, const char * fmt, va_list args) {
int fd = conn->params->trigger_fd;
if (fd != 0) log_timestamp(fd);
else {
fd = conn->params->logfile_fd;
if (fd != 0) log_timestamp(fd);
}
vlog_locked(conn, fmt, args);
}
void log_time_locked(connection_t * connection, const char * fmt, ...) {
va_list args; va_list args;
va_start(args, fmt); va_start(args, fmt);
vlog_time_locked(connection, fmt, args); vlog_sock_locked(fd, fmt, args);
va_end(args); va_end(args);
} }
void log_time(connection_t * connection, const char * fmt, ...) { void die
(int exit_code, parameters * params, const char * parg, const char * fmt, ...)
{
va_list argp, targs;
int in_errno = errno;
int fd = 0;
if (params != NULL) {
fd = params->ctl_sock;
lock("die ctl_lock", &params->ctl_lock);
}
va_start(argp, fmt);
va_copy(targs, argp);
vsyslog(LOG_CRIT, fmt, targs);
va_end(targs);
if (fd != 0) vlog_sock_locked(fd, fmt, argp);
va_end(argp);
if (parg != NULL) {
if (*parg != 0) {
syslog(LOG_CRIT, "%s: %s", parg, strerror(in_errno));
if (fd != 0) log_sock_locked(fd, "%s: %s", parg, strerror(in_errno));
} else {
syslog(LOG_CRIT, "%s", strerror(in_errno));
if (fd != 0) log_sock_locked(fd, "%s", strerror(in_errno));
}
}
exit(exit_code);
// Nobody else should die before we terminate everything
unlock("die ctl_lock", &params->ctl_lock);
}
void vlog_locked(parameters * params, const char * fmt, va_list args) {
int rc;
int fd = params->ctl_sock;
va_list targs;
if (fd != 0) vlog_sock_locked(fd, fmt, args);
else {
va_copy(targs, args);
vsyslog(LOG_INFO, fmt, targs);
va_end(targs);
fd = params->logfile_fd;
if (fd != 0) {
va_copy(targs, args);
rc = vdprintf(fd, fmt, targs);
if (rc < 0) die(1, NULL, "Couldn't write log message with vdprintf", "");
va_end(targs);
}
}
}
void vlog_time_locked(parameters * params, const char * fmt, va_list args) {
int fd = params->logfile_fd;
if (fd != 0 && params->ctl_sock == 0) log_timestamp(fd);
vlog_locked(params, fmt, args);
}
void log_time_locked(parameters * params, const char * fmt, ...) {
va_list args; va_list args;
va_start(args, fmt); va_start(args, fmt);
lock("log_time fd_lock", &connection->params->fd_lock); vlog_time_locked(params, fmt, args);
vlog_time_locked(connection, fmt, args);
unlock("log_time fd_lock", &connection->params->fd_lock); va_end(args);
}
void log_time(parameters * params, const char * fmt, ...) {
va_list args;
va_start(args, fmt);
lock("log_time ctl_lock", &params->ctl_lock);
vlog_time_locked(params, fmt, args);
unlock("log_time ctl_lock", &params->ctl_lock);
va_end(args); va_end(args);
} }
typedef struct { typedef struct {
connection_t * connection; parameters * params;
char * msg; char * msg;
} log_thread_state; } log_thread_state;
void * log_time_thread(void * log_state_ptr) { void * log_time_thread(void * log_state_ptr) {
log_thread_state * log_state = log_state_ptr; log_thread_state * log_state = log_state_ptr;
log_time(log_state->connection, log_state->msg); log_time(log_state->params, log_state->msg);
free(log_state->msg); free(log_state->msg);
free(log_state); free(log_state);
@ -117,11 +184,11 @@ void thread_log_time(connection_t * conn, const char * fmt, ...) {
log_state = must_malloc("thread_log_time log_state", log_state = must_malloc("thread_log_time log_state",
sizeof(log_thread_state)); sizeof(log_thread_state));
log_state->connection = conn; log_state->params = conn->params;
va_start(args, fmt); va_start(args, fmt);
if (vasprintf(&log_state->msg, fmt, args) == -1) if (vasprintf(&log_state->msg, fmt, args) == -1)
die(1, "Couldn't allocate thread_log_time message", ""); die(1, conn->params, "Couldn't allocate thread_log_time message", "");
va_end(args); va_end(args);
// TODO: We currently spawn a new thread for every message. This is // TODO: We currently spawn a new thread for every message. This is
@ -129,28 +196,29 @@ void thread_log_time(connection_t * conn, const char * fmt, ...) {
// log demand to be low. // log demand to be low.
if ((errno = pthread_create(&logger, &detached, log_time_thread, log_state))) if ((errno = pthread_create(&logger, &detached, log_time_thread, log_state)))
die(1, "", "Couldn't create log thread for %s connection %s: ", die(1, conn->params, "",
"Couldn't create log thread for %s connection %s: ",
conn->type_descr, conn->mount_point); conn->type_descr, conn->mount_point);
} }
void log_continue_locked(connection_t * connection, const char * fmt, ...) { void log_continue_locked(parameters * params, const char * fmt, ...) {
va_list args; va_list args;
va_start(args, fmt); va_start(args, fmt);
vlog_locked(connection, fmt, args); vlog_locked(params, fmt, args);
va_end(args); va_end(args);
} }
void log_continue(connection_t * connection, const char * fmt, ...) { void log_continue(parameters * params, const char * fmt, ...) {
va_list args; va_list args;
va_start(args, fmt); va_start(args, fmt);
lock("log_continue fd_lock", &connection->params->fd_lock); lock("log_continue ctl_lock", &params->ctl_lock);
vlog_locked(connection, fmt, args); vlog_locked(params, fmt, args);
unlock("log_continue fd_lock", &connection->params->fd_lock); unlock("log_continue ctl_lock", &params->ctl_lock);
va_end(args); va_end(args);
} }

View File

@ -2,18 +2,20 @@
#include "transfused.h" #include "transfused.h"
void die(int exit_code, const char * perror_arg, const char * fmt, ...); void die
(int exit_code, parameters * params, const char * perror_arg,
const char * fmt, ...);
void vlog_locked(connection_t * conn, const char * fmt, va_list args); void vlog_locked(parameters * params, const char * fmt, va_list args);
void vlog_time_locked(connection_t * conn, const char * fmt, va_list args); void vlog_time_locked(parameters * params, const char * fmt, va_list args);
void log_time_locked(connection_t * connection, const char * fmt, ...); void log_time_locked(parameters * params, const char * fmt, ...);
void log_time(connection_t * connection, const char * fmt, ...); void log_time(parameters * params, const char * fmt, ...);
void thread_log_time(connection_t * connection, const char * fmt, ...); void thread_log_time(connection_t * conn, const char * fmt, ...);
void log_continue_locked(connection_t * connection, const char * fmt, ...); void log_continue_locked(parameters * params, const char * fmt, ...);
void log_continue(connection_t * connection, const char * fmt, ...); void log_continue(parameters * params, const char * fmt, ...);

View File

@ -12,7 +12,7 @@ long parse_cid(const char * address) {
long cid = strtol(address, &end, 10); long cid = strtol(address, &end, 10);
if (address == end || *end != ':') { if (address == end || *end != ':') {
*end = 0; *end = 0;
die(2, NULL, "Invalid vsock cid: %s", address); die(2, NULL, NULL, "Invalid vsock cid: %s", address);
} }
return cid; return cid;
} }
@ -22,7 +22,7 @@ long parse_port(const char * port_str) {
long port = strtol(port_str, &end, 10); long port = strtol(port_str, &end, 10);
if (port_str == end || *end != '\0') { if (port_str == end || *end != '\0') {
*end = 0; *end = 0;
die(2, NULL, "Invalid vsock port: %s", port_str); die(2, NULL, NULL, "Invalid vsock port: %s", port_str);
} }
return port; return port;
} }
@ -35,7 +35,7 @@ int find_colon(const char * address) {
else colon++; else colon++;
if (address[colon] == '\0') if (address[colon] == '\0')
die(2, NULL, "Missing port in vsock address %s", address); die(2, NULL, NULL, "Missing port in vsock address %s", address);
return colon; return colon;
} }
@ -62,10 +62,10 @@ int bind_vsock(const char * address) {
sock_fd = socket(AF_VSOCK, SOCK_STREAM, 0); sock_fd = socket(AF_VSOCK, SOCK_STREAM, 0);
if (sock_fd < 0) if (sock_fd < 0)
die(1, "socket(AF_VSOCK)", ""); die(1, NULL, "socket(AF_VSOCK)", "");
if (bind(sock_fd, (struct sockaddr *) &sa_listen, sizeof(sa_listen))) if (bind(sock_fd, (struct sockaddr *) &sa_listen, sizeof(sa_listen)))
die(1, "bind(AF_VSOCK)", ""); die(1, NULL, "bind(AF_VSOCK)", "");
return sock_fd; return sock_fd;
} }
@ -90,10 +90,10 @@ int connect_vsock(const char * address) {
sock_fd = socket(AF_VSOCK, SOCK_STREAM, 0); sock_fd = socket(AF_VSOCK, SOCK_STREAM, 0);
if (sock_fd < 0) if (sock_fd < 0)
die(1, "socket(AF_VSOCK)", ""); die(1, NULL, "socket(AF_VSOCK)", "");
if (connect(sock_fd, (struct sockaddr *) &sa_connect, sizeof(sa_connect))) if (connect(sock_fd, (struct sockaddr *) &sa_connect, sizeof(sa_connect)))
die(1, "connect(AF_VSOCK)", ""); die(1, NULL, "connect(AF_VSOCK)", "");
return sock_fd; return sock_fd;
} }