Add message logging to udscs

6 files changed, 136 insertions, 106 deletions

diff --git a/udscs.c b/udscs.c
index ec98773..8389697 100644
--- a/udscs.c
+++ b/udscs.c
@@ -40,6 +40,10 @@ struct udscs_buf {
 
 struct udscs_connection {
     int fd;
+    const char * const *type_to_string;
+    int no_types;
+    FILE *logfile;
+    FILE *errfile;
 
     /* Read stuff, single buffer, separate header and data buffer */
     int header_read;
@@ -60,6 +64,10 @@ struct udscs_connection {
 
 struct udscs_server {
     int fd;
+    const char * const *type_to_string;
+    int no_types;
+    FILE *logfile;
+    FILE *errfile;
     struct udscs_connection connections_head;
     udscs_connect_callback connect_callback;
     udscs_read_callback read_callback;
@@ -73,7 +81,9 @@ static void udscs_do_read(struct udscs_connection **connp);
 struct udscs_server *udscs_create_server(const char *socketname,
     udscs_connect_callback connect_callback,
     udscs_read_callback read_callback,
-    udscs_disconnect_callback disconnect_callback)
+    udscs_disconnect_callback disconnect_callback,
+    const char * const type_to_string[], int no_types,
+    FILE *logfile, FILE *errfile)
 {
     int c;
     struct sockaddr_un address;
@@ -83,16 +93,23 @@ struct udscs_server *udscs_create_server(const char *socketname,
     if (!server)
         return NULL;
 
+    server->logfile = logfile;
+    server->errfile = errfile;
+    server->type_to_string = type_to_string;
+    server->no_types = no_types;
+
     server->fd = socket(PF_UNIX, SOCK_STREAM, 0);
     if (server->fd == -1) {
-        perror("creating unix domain socket");
+        fprintf(server->errfile, "creating unix domain socket: %s\n",
+                strerror(errno));
         free(server);
         return NULL;
     }
 
     c = unlink(socketname);
     if (c != 0 && errno != ENOENT) {
-        fprintf(stderr, "unlink %s: %s\n", socketname, strerror(errno));
+        fprintf(server->errfile, "unlink %s: %s\n", socketname,
+                strerror(errno));
         free(server);
         return NULL;
     }
@@ -101,14 +118,14 @@ struct udscs_server *udscs_create_server(const char *socketname,
     snprintf(address.sun_path, sizeof(address.sun_path), "%s", socketname);
     c = bind(server->fd, (struct sockaddr *)&address, sizeof(address));
     if (c != 0) {
-        fprintf(stderr, "bind %s: %s\n", socketname, strerror(errno));
+        fprintf(server->errfile, "bind %s: %s\n", socketname, strerror(errno));
         free(server);
         return NULL;
     }
 
     c = listen(server->fd, 5);
     if (c != 0) {
-        perror("listen");
+        fprintf(server->errfile, "listen: %s\n", strerror(errno));
         free(server);
         return NULL;
     }
@@ -139,7 +156,9 @@ void udscs_destroy_server(struct udscs_server *server)
 
 struct udscs_connection *udscs_connect(const char *socketname,
     udscs_read_callback read_callback,
-    udscs_disconnect_callback disconnect_callback)
+    udscs_disconnect_callback disconnect_callback,
+    const char * const type_to_string[], int no_types,
+    FILE *logfile, FILE *errfile)
 {
     int c;
     struct sockaddr_un address;
@@ -149,9 +168,15 @@ struct udscs_connection *udscs_connect(const char *socketname,
     if (!conn)
         return NULL;
 
+    conn->logfile = logfile;
+    conn->errfile = errfile;
+    conn->type_to_string = type_to_string;
+    conn->no_types = no_types;
+
     conn->fd = socket(PF_UNIX, SOCK_STREAM, 0);
     if (conn->fd == -1) {
-        perror("creating unix domain socket");
+        fprintf(conn->errfile, "creating unix domain socket: %s\n",
+                strerror(errno));
         free(conn);
         return NULL;
     }
@@ -160,7 +185,8 @@ struct udscs_connection *udscs_connect(const char *socketname,
     snprintf(address.sun_path, sizeof(address.sun_path), "%s", socketname);
     c = connect(conn->fd, (struct sockaddr *)&address, sizeof(address));
     if (c != 0) {
-        fprintf(stderr, "connect %s: %s\n", socketname, strerror(errno));
+        fprintf(conn->errfile, "connect %s: %s\n", socketname,
+                strerror(errno));
         free(conn);
         return NULL;
     }
@@ -168,6 +194,9 @@ struct udscs_connection *udscs_connect(const char *socketname,
     conn->read_callback = read_callback;
     conn->disconnect_callback = disconnect_callback;
 
+    if (conn->logfile)
+        fprintf(conn->logfile, "%p connected to %s\n", conn, socketname);
+
     return conn;
 }
 
@@ -196,6 +225,10 @@ void udscs_destroy_connection(struct udscs_connection **connp)
         conn->prev->next = conn->next;
 
     close(conn->fd);
+
+    if (conn->logfile)
+        fprintf(conn->logfile, "%p disconnected\n", conn);
+
     free(conn);
     *connp = NULL;
 }
@@ -246,18 +279,22 @@ static void udscs_server_accept(struct udscs_server *server) {
     if (fd == -1) {
         if (errno == EINTR)
             return;
-        perror("accept");
+        fprintf(server->errfile, "accept: %s\n", strerror(errno));
         return;
     }
 
     new_conn = calloc(1, sizeof(*conn));
     if (!new_conn) {
-        fprintf(stderr, "out of memory, disconnecting client\n");
+        fprintf(server->errfile, "out of memory, disconnecting new client\n");
         close(fd);
         return;
     }
 
     new_conn->fd = fd;
+    new_conn->logfile = server->logfile;
+    new_conn->errfile = server->errfile;
+    new_conn->type_to_string = server->type_to_string;
+    new_conn->no_types = server->no_types;
     new_conn->read_callback = server->read_callback;
     new_conn->disconnect_callback = server->disconnect_callback;
 
@@ -268,6 +305,9 @@ static void udscs_server_accept(struct udscs_server *server) {
     new_conn->prev = conn;
     conn->next = new_conn;
 
+    if (server->logfile)
+        fprintf(server->logfile, "new client accepted: %p\n", new_conn);
+
     if (server->connect_callback)
         server->connect_callback(new_conn);
 }
@@ -332,6 +372,16 @@ int udscs_write(struct udscs_connection *conn, uint32_t type, uint32_t opaque,
     memcpy(new_wbuf->buf, &header, sizeof(header));
     memcpy(new_wbuf->buf + sizeof(header), data, size);
 
+    if (conn->logfile) {
+        if (type < conn->no_types)
+            fprintf(conn->logfile, "%p sent %s, opaque: %u, size %u\n",
+                    conn, conn->type_to_string[type], opaque, size);
+        else
+            fprintf(conn->logfile,
+                    "%p sent invalid message %u, opaque: %u, size %u\n",
+                    conn, type, opaque, size);
+    }
+
     if (!conn->write_buf) {
         conn->write_buf = new_wbuf;
         return 0;
@@ -363,12 +413,39 @@ int udscs_server_write_all(struct udscs_server *server,
     return 0;
 }
 
+static void udscs_read_complete(struct udscs_connection **connp)
+{
+    struct udscs_connection *conn = *connp;
+
+    if (conn->logfile) {
+        if (conn->header.type < conn->no_types)
+            fprintf(conn->logfile, "%p received %s, opaque: %u, size %u\n",
+                    conn, conn->type_to_string[conn->header.type],
+                    conn->header.opaque, conn->header.size);
+        else
+            fprintf(conn->logfile,
+                    "%p received invalid message %u, opaque: %u, size %u\n",
+                    conn, conn->header.type, conn->header.opaque,
+                    conn->header.size);
+    }
+
+    if (conn->read_callback) {
+        if (conn->read_callback(conn, &conn->header, conn->data.buf) == -1) {
+            udscs_destroy_connection(connp);
+            return;
+        }
+    }
+
+    free(conn->data.buf);
+    conn->header_read = 0;
+    memset(&conn->data, 0, sizeof(conn->data));
+}
+
 static void udscs_do_read(struct udscs_connection **connp)
 {
     ssize_t n;
     size_t to_read;
     uint8_t *dest;
-    int r;
     struct udscs_connection *conn = *connp;
 
     if (conn->header_read < sizeof(conn->header)) {
@@ -383,7 +460,9 @@ static void udscs_do_read(struct udscs_connection **connp)
     if (n < 0) {
         if (errno == EINTR)
             return;
-        perror("reading from unix domain socket");
+        fprintf(conn->errfile,
+                "reading unix domain socket: %s, disconnecting %p\n",
+                strerror(errno), conn);
     }
     if (n <= 0) {
         udscs_destroy_connection(connp);
@@ -394,39 +473,23 @@ static void udscs_do_read(struct udscs_connection **connp)
         conn->header_read += n;
         if (conn->header_read == sizeof(conn->header)) {
             if (conn->header.size == 0) {
-                if (conn->read_callback) {
-                    r = conn->read_callback(conn, &conn->header, NULL);
-                    if (r == -1) {
-                        udscs_destroy_connection(connp);
-                        return;
-                    }
-                }
-                conn->header_read = 0;
-            } else {
-                conn->data.pos = 0;
-                conn->data.size = conn->header.size;
-                conn->data.buf = malloc(conn->data.size);
-                if (!conn->data.buf) {
-                    fprintf(stderr, "out of memory, disconnecting client\n");
-                    udscs_destroy_connection(connp);
-                    return;
-                }
+                udscs_read_complete(connp);
+                return;
+            }
+            conn->data.pos = 0;
+            conn->data.size = conn->header.size;
+            conn->data.buf = malloc(conn->data.size);
+            if (!conn->data.buf) {
+                fprintf(conn->errfile, "out of memory, disconnecting %p\n",
+                        conn);
+                udscs_destroy_connection(connp);
+                return;
             }
         }
     } else {
         conn->data.pos += n;
-        if (conn->data.pos == conn->data.size) {
-            if (conn->read_callback) {
-                r = conn->read_callback(conn, &conn->header, conn->data.buf);
-                if (r == -1) {
-                    udscs_destroy_connection(connp);
-                    return;
-                }
-            }
-            free(conn->data.buf);
-            conn->header_read = 0;
-            memset(&conn->data, 0, sizeof(conn->data));
-        }
+        if (conn->data.pos == conn->data.size)
+            udscs_read_complete(connp);
     }
 }
 
@@ -438,8 +501,9 @@ static void udscs_do_write(struct udscs_connection **connp)
 
     struct udscs_buf* wbuf = conn->write_buf;
     if (!wbuf) {
-        fprintf(stderr,
-                "do_write called on a connection without a write buf ?!\n");
+        fprintf(conn->errfile,
+                "%p do_write called on a connection without a write buf ?!\n",
+                conn);
         return;
     }
 
@@ -448,7 +512,9 @@ static void udscs_do_write(struct udscs_connection **connp)
     if (n < 0) {
         if (errno == EINTR)
             return;
-        perror("writing to unix domain socket");
+        fprintf(conn->errfile,
+                "writing to unix domain socket: %s, disconnecting %p\n",
+                strerror(errno), conn);
         udscs_destroy_connection(connp);
         return;
     }
diff --git a/udscs.h b/udscs.h
index fe44e4b..e7a9ee0 100644
--- a/udscs.h
+++ b/udscs.h
@@ -22,6 +22,7 @@
 #ifndef __UDSCS_H
 #define __UDSCS_H
 
+#include <stdio.h>
 #include <stdint.h>
 #include <sys/select.h>
 
@@ -31,7 +32,6 @@ struct udscs_message_header {
     uint32_t type;
     uint32_t opaque;
     uint32_t size;  
-    uint8_t data[0];
 };
 
 /* Callbacks with this type will be called when a new connection to a
@@ -57,14 +57,18 @@ typedef void (*udscs_disconnect_callback)(struct udscs_connection *conn);
 struct udscs_server *udscs_create_server(const char *socketname,
     udscs_connect_callback connect_callback,
     udscs_read_callback read_callback,
-    udscs_disconnect_callback disconnect_callback);
+    udscs_disconnect_callback disconnect_callback,
+    const char * const type_to_string[], int no_types,
+    FILE *logfile, FILE *errfile);
 
 void udscs_destroy_server(struct udscs_server *server);
 
 /* Connect to a unix domain socket named name. */
 struct udscs_connection *udscs_connect(const char *socketname,
     udscs_read_callback read_callback,
-    udscs_disconnect_callback disconnect_callback);
+    udscs_disconnect_callback disconnect_callback,
+    const char * const type_to_string[], int no_types,
+    FILE *logfile, FILE *errfile);
 
 /* The contents of connp will be made NULL */
 void udscs_destroy_connection(struct udscs_connection **connp);
diff --git a/vdagent-x11.c b/vdagent-x11.c
index 3de2b58..08d93db 100644
--- a/vdagent-x11.c
+++ b/vdagent-x11.c
@@ -59,7 +59,6 @@ struct vdagent_x11 {
 };
 
 static void vdagent_x11_send_daemon_guest_xorg_res(struct vdagent_x11 *x11);
-static void vdagent_x11_send_daemon_clipboard_grab(struct vdagent_x11 *x11);
 static void vdagent_x11_handle_selection_notify(struct vdagent_x11 *x11,
                                                 XEvent *event);
 
@@ -165,7 +164,11 @@ void vdagent_x11_do_read(struct vdagent_x11 *x11)
             return;
         }
 
-        vdagent_x11_send_daemon_clipboard_grab(x11);
+        /* FIXME plenty, we need to request the selection with a type of
+           TARGETS and then compare the TARGETS against our list of known
+           UTF-8 targets. */
+        udscs_write(x11->vdagentd, VDAGENTD_CLIPBOARD_GRAB,
+                    VD_AGENT_CLIPBOARD_UTF8_TEXT, NULL, 0);
         handled = 1;
     } else switch (event.type) {
     case ConfigureNotify:
@@ -209,27 +212,6 @@ static void vdagent_x11_send_daemon_guest_xorg_res(struct vdagent_x11 *x11)
                 (uint8_t *)&res, sizeof(res));
 }
 
-static void vdagent_x11_send_daemon_clipboard_grab(struct vdagent_x11 *x11)
-{
-    /* FIXME plenty, we need to request the selection with a type of
-       TARGETS and then compare the TARGETS against our list of known
-       UTF-8 targets. */
-    uint32_t type = VD_AGENT_CLIPBOARD_UTF8_TEXT;
-
-    udscs_write(x11->vdagentd, VDAGENTD_CLIPBOARD_GRAB, type, NULL, 0);
-    if (x11->verbose)
-        fprintf(stderr, "Claimed clipboard ownership, type: %u\n", type);
-}
-
-static void vdagent_x11_send_daemon_clipboard_data(struct vdagent_x11 *x11,
-    uint32_t type, uint8_t *data, uint32_t size)
-{
-    udscs_write(x11->vdagentd, VDAGENTD_CLIPBOARD_DATA, type, data, size);
-    if (x11->verbose)
-        fprintf(stderr, "Send clipboard data, type: %u, size: %u\n",
-                type, size);
-}
-
 static void vdagent_x11_handle_selection_notify(struct vdagent_x11 *x11,
                                                 XEvent *event)
 {
@@ -270,8 +252,8 @@ static void vdagent_x11_handle_selection_notify(struct vdagent_x11 *x11,
     }
 
     /* FIXME don't hardcode VD_AGENT_CLIPBOARD_UTF8_TEXT */
-    vdagent_x11_send_daemon_clipboard_data(x11, VD_AGENT_CLIPBOARD_UTF8_TEXT,
-                                           data, len);
+    udscs_write(x11->vdagentd, VDAGENTD_CLIPBOARD_DATA,
+                VD_AGENT_CLIPBOARD_UTF8_TEXT, data, len);
     XFree(data);
     return;
 
@@ -279,8 +261,8 @@ error:
     if (data)
         XFree(data);
     /* Notify the spice client that no answer is forthcoming */
-    vdagent_x11_send_daemon_clipboard_data(x11, VD_AGENT_CLIPBOARD_NONE,
-                                           NULL, 0);
+    udscs_write(x11->vdagentd, VDAGENTD_CLIPBOARD_DATA,
+                VD_AGENT_CLIPBOARD_NONE, NULL, 0);
 }
 
 void vdagent_x11_set_monitor_config(struct vdagent_x11 *x11,
@@ -348,7 +330,4 @@ void vdagent_x11_clipboard_request(struct vdagent_x11 *x11, uint32_t type)
     XConvertSelection(x11->display, x11->clipboard_atom, target,
                       x11->clipboard_atom, x11->selection_window, CurrentTime);
     XFlush(x11->display);
-    if (x11->verbose)
-        fprintf(stderr, "Requested selection, target: %s\n",
-                XGetAtomName(x11->display, target));
 }
diff --git a/vdagent.c b/vdagent.c
index 28506cc..0bf4a35 100644
--- a/vdagent.c
+++ b/vdagent.c
@@ -29,6 +29,7 @@
 
 #include "udscs.h"
 #include "vdagentd-proto.h"
+#include "vdagentd-proto-strings.h"
 #include "vdagent-x11.h"
 
 static int verbose = 0;
@@ -83,7 +84,9 @@ int main(int argc, char *argv[])
         }
     }
 
-    client = udscs_connect(VDAGENTD_SOCKET, daemon_read_complete, NULL);
+    client = udscs_connect(VDAGENTD_SOCKET, daemon_read_complete, NULL,
+                           vdagentd_messages, VDAGENTD_NO_MESSAGES,
+                           verbose? stderr:NULL, stderr);
     if (!client)
         exit(1);
 
diff --git a/vdagentd-proto.h b/vdagentd-proto.h
index 64a2624..d4e7e69 100644
--- a/vdagentd-proto.h
+++ b/vdagentd-proto.h
@@ -33,6 +33,7 @@ enum {
     VDAGENTD_CLIPBOARD_REQUEST, /* opaque = type */
     VDAGENTD_CLIPBOARD_DATA,    /* opaque = type, data = data */
     VDAGENTD_CLIPBOARD_RELEASE, /* no data */
+    VDAGENTD_NO_MESSAGES /* Must always be last */
 };
 
 struct vdagentd_guest_xorg_resolution {
diff --git a/vdagentd.c b/vdagentd.c
index abb2866..9e3fe8f 100644
--- a/vdagentd.c
+++ b/vdagentd.c
@@ -31,6 +31,7 @@
 
 #include "udscs.h"
 #include "vdagentd-proto.h"
+#include "vdagentd-proto-strings.h"
 #include "vdagentd-uinput.h"
 #include "vdagent-virtio-port.h"
 
@@ -138,18 +139,12 @@ static void do_clipboard(struct vdagent_virtio_port *port,
         VDAgentClipboardGrab *grab = (VDAgentClipboardGrab *)message_data;
         type = VDAGENTD_CLIPBOARD_GRAB;
         opaque = grab->type;
-        if (debug)
-            fprintf(stderr, "Client claimed clipboard owner ship type %u\n",
-                    grab->type);
         break;
     }
     case VD_AGENT_CLIPBOARD_REQUEST: {
         VDAgentClipboardRequest *req = (VDAgentClipboardRequest *)message_data;
         type = VDAGENTD_CLIPBOARD_REQUEST;
         opaque = req->type;
-        if (debug)
-            fprintf(stderr, "Client send clipboard request type %u\n",
-                    req->type);
         break;
     }
     case VD_AGENT_CLIPBOARD: {
@@ -158,15 +153,10 @@ static void do_clipboard(struct vdagent_virtio_port *port,
         opaque = clipboard->type;
         size = message_header->size - sizeof(VDAgentClipboard);
         data = clipboard->data;
-        if (debug)
-            fprintf(stderr, "Client send clipboard data type %u\n",
-                    clipboard->type);
         break;
     }
     case VD_AGENT_CLIPBOARD_RELEASE:
         type = VDAGENTD_CLIPBOARD_RELEASE;
-        if (debug)
-            fprintf(stderr, "Client released clipboard\n");
         break;
     }
 
@@ -253,10 +243,6 @@ void do_client_clipboard(struct udscs_connection *conn,
         vdagent_virtio_port_write(virtio_port, VDP_CLIENT_PORT,
                                   VD_AGENT_CLIPBOARD_GRAB, 0,
                                   (uint8_t *)&grab, sizeof(grab));
-        if (debug)
-            fprintf(stderr,
-                    "Agent: %p claimed clipboard owner ship type %u\n",
-                    conn, grab.type);
         break;
     }
     case VDAGENTD_CLIPBOARD_REQUEST: {
@@ -264,9 +250,6 @@ void do_client_clipboard(struct udscs_connection *conn,
         vdagent_virtio_port_write(virtio_port, VDP_CLIENT_PORT,
                                   VD_AGENT_CLIPBOARD_REQUEST, 0,
                                   (uint8_t *)&req, sizeof(req));
-        if (debug)
-            fprintf(stderr, "Agent: %p send a clipboard request type %u\n",
-                    conn, req.type);
         break;
     }
     case VDAGENTD_CLIPBOARD_DATA: {
@@ -285,18 +268,12 @@ void do_client_clipboard(struct udscs_connection *conn,
         vdagent_virtio_port_write(virtio_port, VDP_CLIENT_PORT,
                                   VD_AGENT_CLIPBOARD, 0,
                                   (uint8_t *)clipboard, size);
-        if (debug)
-            fprintf(stderr, "Agent: %p send clipboard data type %u\n",
-                    conn, clipboard->type);
         free(clipboard);
         break;
     }
     case VDAGENTD_CLIPBOARD_RELEASE:
         vdagent_virtio_port_write(virtio_port, VDP_CLIENT_PORT,
                                   VD_AGENT_CLIPBOARD_RELEASE, 0, NULL, 0);
-        if (debug)
-            fprintf(stderr, "Agent: %p released clipboard owner ship\n",
-                    conn);
         break;
     }
 
@@ -460,10 +437,10 @@ int main(int argc, char *argv[])
     }
 
     /* Setup communication with vdagent process(es) */
-    server = udscs_create_server(VDAGENTD_SOCKET,
-                                 client_connect,
-                                 client_read_complete,
-                                 client_disconnect);
+    server = udscs_create_server(VDAGENTD_SOCKET, client_connect,
+                                 client_read_complete, client_disconnect,
+                                 vdagentd_messages, VDAGENTD_NO_MESSAGES,
+                                 debug? stderr:NULL, stderr);
     if (!server)
         exit(1);