commit 5e03b78d5aacaf06e74917ba3dc386df46646e03
Author: Tom Mullins <tmullins@andrew.cmu.edu>
Date:   Sun May 5 16:36:57 2013 -0400

    Added new logging functions which inject timestamps

diff --git a/mainbox/Makefile b/mainbox/Makefile
index 0008398..b323dda 100644
--- a/mainbox/Makefile
+++ b/mainbox/Makefile
@@ -1,5 +1,5 @@
-SRC=main.c tool.c query.c event.c util.c
-HDR=tool.h query.h event.h util.h ../tooltron_mb.h
+SRC=main.c tool.c query.c event.c util.c log.c
+HDR=tool.h query.h event.h util.h log.h ../tooltron_mb.h
 
 FLAGS=-O2 -g -Wall -I.. `pkg-config --cflags --libs libmodbus libcurl`
 
diff --git a/mainbox/log.c b/mainbox/log.c
new file mode 100644
index 0000000..bc0cdfe
--- /dev/null
+++ b/mainbox/log.c
@@ -0,0 +1,28 @@
+#include "log.h"
+#include <stdio.h>
+#include <stdarg.h>
+#include <time.h>
+#include <errno.h>
+#include <sys/time.h>
+
+void log_time() {
+  char buf[100];
+  time_t t;
+  time(&t);
+  strftime(buf, sizeof(buf), "%b %e %T %Y", localtime(&t));
+  printf("[%s] ", buf);
+}
+
+void log_print(const char *fmt, ...) {
+  va_list args;
+  va_start(args, fmt);
+  log_time();
+  vprintf(fmt, args);
+  printf("\n");
+  va_end(args);
+}
+
+void log_perror(const char *s) {
+  log_time();
+  perror(s);
+}
diff --git a/mainbox/log.h b/mainbox/log.h
new file mode 100644
index 0000000..d5be558
--- /dev/null
+++ b/mainbox/log.h
@@ -0,0 +1,7 @@
+#ifndef LOG_H
+#define LOG_H
+
+void log_print(const char *fmt, ...);
+void log_perror(const char *s);
+
+#endif
diff --git a/mainbox/main.c b/mainbox/main.c
index eab44f9..bb73d5e 100644
--- a/mainbox/main.c
+++ b/mainbox/main.c
@@ -1,5 +1,6 @@
 #include "tool.h"
 #include "query.h"
+#include "log.h"
 #include <unistd.h>
 #include <signal.h>
 #include <strings.h>
@@ -59,8 +60,8 @@ int main(int argc, char **argv) {
     }
   }
 
-  printf("Serial device: %s\n", device);
-  printf("CRM server: http://%s/\n", server);
+  log_print("Serial device: %s", device);
+  log_print("CRM server: http://%s/", server);
 
   bzero(&sigact, sizeof(sigact));
   sigact.sa_handler = sigint;
@@ -76,7 +77,7 @@ int main(int argc, char **argv) {
     return 1;
   }
 
-  printf("Modbus initialized; polling tools...\n");
+  log_print("Modbus initialized; polling tools...");
 
   i = 0;
   while (run) {
@@ -86,14 +87,14 @@ int main(int argc, char **argv) {
     i = (i+1) % N_TOOLS;
   }
 
-  printf("\nDisabling tools\n");
+  log_print("Disabling tools");
   for (i = 0; i < N_TOOLS; i++) {
     tool_request_disable(&tools[i]);
   }
 
-  printf("Closing modbus connection\n");
+  log_print("Closing modbus connection");
   tool_close_mb();
 
-  printf("Exiting\n");
+  log_print("Exiting");
   return 0;
 }
diff --git a/mainbox/query.c b/mainbox/query.c
index 38be90c..71a9f9d 100644
--- a/mainbox/query.c
+++ b/mainbox/query.c
@@ -1,6 +1,7 @@
 #include "query.h"
 #include "event.h"
 #include "util.h"
+#include "log.h"
 #include <stdlib.h>
 #include <stdio.h>
 #include <string.h>
@@ -20,7 +21,7 @@ int query_init(const char *server_name) {
 
   error_code = curl_global_init(CURL_GLOBAL_SSL);
   if (error_code) {
-    fprintf(stderr, "curl_global_init: %s\n", curl_easy_strerror(error_code));
+    log_print("ERROR: curl_global_init: %s\n", curl_easy_strerror(error_code));
     return error_code;
   }
 
@@ -90,16 +91,16 @@ int query_user_permission(int tool_id, unsigned int user_id) {
   error_code = curl_easy_getinfo(handle, CURLINFO_RESPONSE_CODE, &response);
   if (error_code) goto error;
   if (response >= 400)
-    fprintf(stderr, "Error %ld from %s\n", response, url);
+    log_print("ERROR: response %ld from %s", response, url);
   else if (response > 200)
-    fprintf(stderr, "Warning: response %ld from %s\n", response, url);
+    log_print("WARNING: response %ld from %s", response, url);
 
   curl_easy_cleanup(handle);
   return result;
 
 error:
-  fprintf(stderr, "curl: %s\n", curl_easy_strerror(error_code));
-  fprintf(stderr, "      when authenticating user %08x on tool %d\n",
+  log_print("ERROR: curl: %s", curl_easy_strerror(error_code));
+  log_print("ERROR:       when authenticating user %08x on tool %d",
       user_id, tool_id);
   curl_easy_cleanup(handle);
   return 0;
@@ -205,9 +206,9 @@ int query_add_event(struct event_t *event) {
   error_code = curl_easy_getinfo(handle, CURLINFO_RESPONSE_CODE, &response);
   if (error_code) goto error;
   if (response >= 400)
-    fprintf(stderr, "Error %ld from %s\n", response, buf);
+    log_print("ERROR: response %ld from %s", response, buf);
   else if (response > 200)
-    fprintf(stderr, "Warning: response %ld from %s\n", response, buf);
+    log_print("WARNING: response %ld from %s", response, buf);
 
   curl_easy_cleanup(handle);
   curl_formfree(formpost);
@@ -217,7 +218,7 @@ int query_add_event(struct event_t *event) {
   return response >= 300;
 
 error:
-  fprintf(stderr, "curl: %s\n", curl_easy_strerror(error_code));
+  log_print("ERROR: curl: %s", curl_easy_strerror(error_code));
   curl_easy_cleanup(handle);
   curl_formfree(formpost);
 #ifdef DEBUG_EVENT_RESPONSE
diff --git a/mainbox/tool.c b/mainbox/tool.c
index fe0169f..f9521f7 100644
--- a/mainbox/tool.c
+++ b/mainbox/tool.c
@@ -1,6 +1,7 @@
 #include "tool.h"
 #include "query.h"
 #include "event.h"
+#include "log.h"
 #include "tooltron_mb.h"
 #include <modbus.h>
 #include <stdio.h>
@@ -13,18 +14,19 @@ int tool_init_mb(const char *device) {
 
   ctx = modbus_new_rtu(device, MB_BAUD, 'N', 8, 1);
   if (ctx == NULL) {
-    fprintf(stderr, "modbus_new_rtu: %s\n", modbus_strerror(errno));
+    log_print("ERROR: modbus_new_rtu: %s", modbus_strerror(errno));
     return 1;
   }
 
   if (modbus_connect(ctx) == -1) {
-    fprintf(stderr, "modbus_connect: %s\n", modbus_strerror(errno));
+    log_print("ERROR: modbus_connect: %s", modbus_strerror(errno));
     modbus_free(ctx);
     return 1;
   }
 
   modbus_get_response_timeout(ctx, &timeout);
-  printf("Response timeout is %lus %luus\n", timeout.tv_sec, timeout.tv_usec);
+  log_print("Modbus response timeout is %lus %luus",
+      timeout.tv_sec, timeout.tv_usec);
 
   return 0;
 }
@@ -36,7 +38,7 @@ void tool_close_mb() {
 
 static void tool_write_coil(int addr, int bit) {
   if (modbus_write_bit(ctx, addr, bit) == -1) {
-    fprintf(stderr, "modbus_write_bit: %s\n", modbus_strerror(errno));
+    log_print("ERROR: modbus_write_bit: %s", modbus_strerror(errno));
   }
 }
 
@@ -49,7 +51,7 @@ static void tool_init(struct tool_t *tool) {
 static void tool_read_user(struct tool_t *tool) {
   unsigned short serno[2];
   if (modbus_read_input_registers(ctx, MB_INP_SERNOL, 2, serno) == -1) {
-    fprintf(stderr, "modbus_read_registers: %s\n", modbus_strerror(errno));
+    log_print("ERROR: modbus_read_registers: %s", modbus_strerror(errno));
     tool->user = 0;
   } else {
     tool->user = MODBUS_GET_INT32_FROM_INT16(serno, 0);
@@ -58,7 +60,7 @@ static void tool_read_user(struct tool_t *tool) {
 
 static void tool_grant_access(struct tool_t *tool) {
 
-  printf("Granting access to %08x on %s (%d)\n", tool->user, tool->name,
+  log_print("Granting access to %08x on %s (%d)", tool->user, tool->name,
       tool->address);
 
   tool_write_coil(MB_COIL_EN, 1);
@@ -74,7 +76,7 @@ static void tool_grant_access(struct tool_t *tool) {
 static void tool_deny_access(struct tool_t *tool) {
   struct event_t *event;
 
-  printf("Denying access to %08x on %s (%d)\n", tool->user, tool->name,
+  log_print("Denying access to %08x on %s (%d)", tool->user, tool->name,
       tool->address);
 
   tool_write_coil(MB_COIL_EN, 0);
@@ -97,7 +99,7 @@ static void tool_off(struct tool_t *tool) {
 }
 
 void tool_request_disable(struct tool_t *tool) {
-  printf("Requesting disable on %s (%d)\n", tool->name, tool->address);
+  log_print("Requesting disable on %s (%d)", tool->name, tool->address);
   tool_write_coil(MB_COIL_REQ_DIS, 1);
   tool->state = TS_REQ_DIS;
 }
@@ -106,26 +108,26 @@ void tool_poll(struct tool_t *tool) {
   unsigned char status[N_COILS];
 
   if (modbus_set_slave(ctx, tool->address) == -1) {
-    fprintf(stderr, "modbus_set_slave: %s\n", modbus_strerror(errno));
+    log_print("ERROR: modbus_set_slave: %s", modbus_strerror(errno));
   }
 
   /* If we can't read from the tool, we only want this error message to print
    * once, thus tool->connected */
   if (modbus_read_bits(ctx, 0, N_COILS, status) == -1) {
     if (tool->connected) {
-      fprintf(stderr, "Cannot connect to %s (%d): %s\n", tool->name,
+      log_print("Cannot connect to %s (%d): %s", tool->name,
           tool->address, modbus_strerror(errno));
       tool->connected = 0;
     }
     return;
   } else if (!tool->connected) {
-    fprintf(stderr, "Reconnected to %s (%d)\n", tool->name, tool->address);
+    log_print("Reconnected to %s (%d)", tool->name, tool->address);
     tool->connected = 1;
   }
 
   /*uint16_t current;
   if (modbus_read_input_registers(ctx, MB_INP_CURRENT, 1, &current) == -1) {
-    fprintf(stderr, "modbus_read_registers: %s\n", modbus_strerror(errno));
+    log_print("ERROR: modbus_read_registers: %s", modbus_strerror(errno));
   } else {
     printf("Current: %d\n", current);
   }*/
@@ -156,14 +158,14 @@ void tool_poll(struct tool_t *tool) {
 
     case TS_ON:
       if (!status[MB_COIL_EN]) {
-        printf("Tool %s (%d) is off\n", tool->name, tool->address);
+        log_print("Tool %s (%d) is off", tool->name, tool->address);
         tool_off(tool);
       }
       break;
 
     case TS_REQ_DIS:
       if (!status[MB_COIL_EN]) {
-        printf("Tool %s (%d) is off after requested disable\n", tool->name,
+        log_print("Tool %s (%d) is off after requested disable", tool->name,
             tool->address);
         tool_off(tool);
       }
diff --git a/mainbox/util.c b/mainbox/util.c
index 65fb43a..c448a0a 100644
--- a/mainbox/util.c
+++ b/mainbox/util.c
@@ -1,4 +1,5 @@
 #include "util.h"
+#include "log.h"
 #include <stdlib.h>
 #include <stdio.h>
 #include <unistd.h>
@@ -12,7 +13,7 @@ char *read_file(const char *filename) {
   
   fd = open(filename, O_RDONLY);
   if (fd < 0) {
-    perror("open");
+    log_perror("open");
     return NULL;
   }
 
@@ -38,7 +39,7 @@ char *read_file(const char *filename) {
       close(fd);
       return str;
     } else if (nread < 0) {
-      perror("read");
+      log_perror("read");
       free(str);
       close(fd);
       return NULL;
