improved support for checkpointing operations via serial, several minor fixes

platform/sky/checkpoint-arch.c

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2009, Swedish Institute of Computer Science
+ * Copyright (c) 2010, Swedish Institute of Computer Science
  * All rights reserved.
  *
  * Redistribution and use in source and binary forms, with or without
@@ -33,87 +33,104 @@
 /**
  * \file
  *  Checkpoint library implementation for the Tmote Sky platform.
+ *
  * \author
  *  Fredrik Osterlind <fros@sics.se>
  */
 
 #include "contiki.h"
+
+#include "lib/crc16.h"
 #include "lib/checkpoint.h"
 
 #include "sys/rtimer.h"
 #include "sys/mt.h"
-#include "cfs/cfs.h"
+#include "sys/energest.h"
-#include "cfs/cfs-coffee.h"
+#include "sys/compower.h"
 #include "dev/leds.h"
 #include "dev/watchdog.h"
+#include "dev/serial-line.h"
+#include "dev/uart1.h"
+#include "dev/cc2420.h"
+#include "dev/button-sensor.h"
+#include "cfs/cfs.h"
+#include "cfs/cfs-coffee.h"
 
 #include <io.h>
 #include <signal.h>
 #include <stdio.h>
 
-#define DEBUG 1
+#define DEBUG 0
 #if DEBUG
 #define PRINTF(...) printf(__VA_ARGS__)
 #else
 #define PRINTF(...)
 #endif
 
+#ifndef CHECKPOINT_ROLLBACK_BUTTON
+#define CHECKPOINT_ROLLBACK_BUTTON 1 /* rollback "cp_wdt" on button click */
+#endif /* CHECKPOINT_ROLLBACK_BUTTON */
+
+#if CHECKPOINT_ROLLBACK_BUTTON
+PROCESS(checkpoint_button_process, "Rollback on button");
+#endif /* CHECKPOINT_ROLLBACK_BUTTON */
+
+#define WITH_SERIAL_COMMANDS 0 /* checkpoint via serial port */
+#if WITH_SERIAL_COMMANDS
+#if UART1_CONF_TX_WITH_INTERRUPT
+#error TX_WITH_INTERRUPTS must be 0
+#endif /* UART1_CONF_TX_WITH_INTERRUPT */
+#define PRINTF_COMMAND(...) printf(__VA_ARGS__)
+#else /* WITH_SERIAL_COMMANDS */
+#define PRINTF_COMMAND(...)
+#endif /* WITH_SERIAL_COMMANDS */
+
 #define COMMAND_ROLLBACK 1
 #define COMMAND_CHECKPOINT 2
-#define COMMAND_TBR 3
+#define COMMAND_METRICS 3
-
-#define DATA_AS_HEX 0 /* If false, store binary data */
 
 #define INCLUDE_RAM 1 /* Less then 10240 bytes */
 #define INCLUDE_TIMERS 1 /* 16 bytes */
 #define INCLUDE_LEDS 1 /* 1 bytes */
+/* ... */
 
 /* 10kb memory */
 #define RAM_START 0x1100
 #define RAM_END 0x3900
 
-#define STOP_TIMERS() TACTL &= ~(MC1); TBCTL &= ~(MC1); watchdog_stop();
+#define PAUSE_TIME() \
-#define START_TIMERS() watchdog_start(); TACTL |= MC1; TBCTL |= MC1;
+  TACTL &= ~(MC1); \
+  TBCTL &= ~(MC1); \
+  watchdog_stop();
+#define RESUME_TIME() \
+  TACTL |= MC1; \
+  TBCTL |= MC1; \
+  watchdog_start();
+#define PAUSE_TIME_INT() \
+  dint(); \
+  PAUSE_TIME();
+#define RESUME_TIME_INT() \
+  RESUME_TIME(); \
+  eint();
 
 static struct mt_thread checkpoint_thread;
 static uint8_t preset_cmd;
 static int preset_fd;
 
+/* bookkeeping */
+static int nr_pongs=0, nr_checkpoints=0, nr_rollbacks=0, nr_metrics=0;
+
+/*---------------------------------------------------------------------------*/
 typedef union {
   unsigned char u8[2];
   unsigned short u16;
 } word_union_t;
-
 /*---------------------------------------------------------------------------*/
-static void
+static int
 write_byte(int fd, uint8_t c)
 {
-#if DATA_AS_HEX
+  return cfs_write(fd, &c, 1);
-  uint8_t hex[2];
-  sprintf(hex, "%02x", c);
-  if(cfs_write(fd, hex, 2) != 2) {
-    printf("err #1\n");
-  }
-#else /* DATA_AS_HEX */
-  if(cfs_write(fd, &c, 1) != 1) {
-    printf("err #2\n");
-  }
-#endif /* DATA_AS_HEX */
-}/*---------------------------------------------------------------------------*/
-#if 0
-static void
-write_array(int fd, unsigned char *mem, uint16_t len)
-{
-#if DATA_AS_HEX
-  int i;
-  for(i = 0; i < len; i++) {
-    write_byte(fd, mem[i]);
-  }
-#else /* DATA_AS_HEX */
-  cfs_write(fd, mem, len);
-#endif /* DATA_AS_HEX */
 }
-#endif /* 0 */
 /*---------------------------------------------------------------------------*/
 static void
 write_word(int fd, uint16_t w)
@@ -127,31 +144,9 @@ write_word(int fd, uint16_t w)
 static uint8_t
 read_byte(int fd)
 {
-#if DATA_AS_HEX
-  uint8_t hex[2];
-
-  cfs_read(fd, hex, 2);
-
-  if(hex[0] >= 'A' && hex[0] <= 'F') {
-    hex[0] = (hex[0] - 'A' + 0xa);
-  } else if(hex[0] >= 'a' && hex[0] <= 'f') {
-    hex[0] = (hex[0] - 'a' + 0xa);
-  } else {
-    hex[0] = (hex[0] - '0');
-  }
-  if(hex[1] >= 'A' && hex[1] <= 'F') {
-    hex[1] = (hex[1] - 'A' + 0xa);
-  } else if(hex[1] >= 'a' && hex[1] <= 'f') {
-    hex[1] = (hex[1] - 'a' + 0xa);
-  } else {
-    hex[1] = (hex[1] - '0');
-  }
-  return (uint8_t)((hex[0]<<4)&0xf0) | (hex[1]&0x0f);
-#else /* DATA_AS_HEX */
   uint8_t c;
   cfs_read(fd, &c, 1);
   return c;
-#endif /* DATA_AS_HEX */
 }
 /*---------------------------------------------------------------------------*/
 static uint16_t
@@ -175,33 +170,31 @@ thread_checkpoint(int fd)
   unsigned char *coffee_mem_end = coffee_mem_start + size - 1;
 #endif /* INCLUDE_RAM */
 
-  /*printf("protected thread memory: %u, size=%u\n", (uint16_t) thread_mem_start, sizeof(checkpoint_thread.thread.stack));*/
+  /*PRINTF("protected thread memory: %u, size=%u\n", (uint16_t) thread_mem_start, sizeof(checkpoint_thread.thread.stack));*/
-  /*printf("protected coffee memory: %u, size=%u\n", (uint16_t) coffee_mem_start, size);*/
+  /*PRINTF("protected coffee memory: %u, size=%u\n", (uint16_t) coffee_mem_start, size);*/
 
   /* RAM */
 #if INCLUDE_RAM
   for(addr = (unsigned char *)RAM_START;
-      addr < (unsigned char *)RAM_END;
+  addr < (unsigned char *)RAM_END;
-      addr++) {
+  addr++) {
 
     if((addr >= thread_mem_start && addr <= thread_mem_end)) {
-      /* Writing dummy memory */
+      /* Skip */
-      /*write_byte(fd, 1);*/
       continue;
     }
 
     if((addr >= coffee_mem_start && addr <= coffee_mem_end)) {
-      /* Writing dummy memory */
+      /* Skip */
-      /*write_byte(fd, 2);*/
       continue;
     }
 
     /* TODO Use write_array() */
     write_byte(fd, *addr);
 
-    if(((int)addr % 512) == 0) {
+    /*if(((int)addr % 512) == 0) {
       PRINTF(".");
-    }
+    }*/
   }
 
 #endif /* INCLUDE_RAM */
@@ -243,33 +236,26 @@ thread_rollback(int fd)
   unsigned char *coffee_mem_end = coffee_mem_start + size - 1;
 #endif /* INCLUDE_RAM */
 
-  /*printf("protected thread memory: %u, size=%u\n", (uint16_t) thread_mem_start, sizeof(checkpoint_thread.thread.stack));*/
+  /*PRINTF("protected thread memory: %u, size=%u\n", (uint16_t) thread_mem_start, sizeof(checkpoint_thread.thread.stack));*/
-  /*printf("protected coffee memory: %u, size=%u\n", (uint16_t) coffee_mem_start, size);*/
+  /*PRINTF("protected coffee memory: %u, size=%u\n", (uint16_t) coffee_mem_start, size);*/
 
   /* RAM */
 #if INCLUDE_RAM
   for(addr = (unsigned char *)RAM_START;
-      addr < (unsigned char *)RAM_END;
+  addr < (unsigned char *)RAM_END;
-      addr++) {
+  addr++) {
     if((addr >= thread_mem_start && addr <= thread_mem_end)) {
-      /* Ignoring incoming memory */
+      /* Skip */
-      /*read_byte(fd);*/
       continue;
     }
 
     if((addr >= coffee_mem_start && addr <= coffee_mem_end)) {
-      /* Ignoring incoming memory */
+      /* Skip */
-      /*read_byte(fd);*/
       continue;
     }
 
     *addr = read_byte(fd);
-
-    if(((int)addr % 512) == 0) {
-      PRINTF(".");
-    }
   }
-
 #endif /* INCLUDE_RAM */
 
   /* Timers */
@@ -297,8 +283,34 @@ thread_rollback(int fd)
   read_byte(fd); /* Coffee padding byte */
 }
 /*---------------------------------------------------------------------------*/
+static uint32_t
+thread_metric_tx(void)
+{
+  energest_flush();
+  return energest_type_time(ENERGEST_TYPE_TRANSMIT);
+}
+/*---------------------------------------------------------------------------*/
+static uint32_t
+thread_metric_rx(void)
+{
+  energest_flush();
+  return energest_type_time(ENERGEST_TYPE_LISTEN);
+}
+/*---------------------------------------------------------------------------*/
 static void
-thread_loop(void *data)
+thread_metrics(void)
+{
+  PRINTF_COMMAND("METRICS:START\n");
+  PRINTF_COMMAND("M:RTIMER_NOW:%u\n", RTIMER_NOW()); /* TODO extract */
+  PRINTF_COMMAND("M:ENERGY_TX:%lu\n", thread_metric_tx());
+  PRINTF_COMMAND("M:ENERGY_RX:%lu\n", thread_metric_rx());
+  PRINTF_COMMAND("M:RTIMER_NOW2:%u\n", RTIMER_NOW());
+  nr_metrics++;
+  PRINTF_COMMAND("METRICS:DONE %u\n", nr_metrics);
+}
+/*---------------------------------------------------------------------------*/
+static void
+checkpoint_thread_loop(void *data)
 {
   uint8_t cmd;
   int fd;
@@ -310,22 +322,24 @@ thread_loop(void *data)
 
     /* Handle command */
     if(cmd == COMMAND_ROLLBACK) {
-      PRINTF("Rolling back");
+      PRINTF_COMMAND("RB:START\n");
       thread_rollback(fd);
-      PRINTF(" done!\n");
+      nr_rollbacks++;
+      PRINTF_COMMAND("RB:DONE %u\n", nr_rollbacks);
+      /* TODO Synch before leaving this thread. */
     } else if(cmd == COMMAND_CHECKPOINT) {
-      PRINTF("Checkpointing");
+      PRINTF_COMMAND("CP:START\n");
       thread_checkpoint(fd);
-      PRINTF(" done!\n");
+      thread_metrics();
-    } else if(cmd == COMMAND_TBR) {
+      nr_checkpoints++;
-      PRINTF("Writing TBR");
+      PRINTF_COMMAND("CP:DONE %u\n", nr_checkpoints);
-      write_word(fd, TBR);
+    } else if(cmd == COMMAND_METRICS) {
-      PRINTF(" done!\n");
+      thread_metrics();
     } else {
-      printf("Error: unknown command: %u\n", cmd);
+      printf("ERROR: Unknown thread command: %u\n", cmd);
     }
 
-    /* Return to main Contiki thread */
+    /* Return to Contiki */
     mt_yield();
   }
 }
@@ -339,34 +353,337 @@ checkpoint_arch_size()
 void
 checkpoint_arch_checkpoint(int fd)
 {
-  STOP_TIMERS();
+  PAUSE_TIME_INT();
 
   preset_cmd = COMMAND_CHECKPOINT;
   preset_fd = fd;
   mt_exec(&checkpoint_thread);
 
-  START_TIMERS();
+  RESUME_TIME_INT();
 }
 /*---------------------------------------------------------------------------*/
 void
 checkpoint_arch_rollback(int fd)
 {
-  STOP_TIMERS();
+  PAUSE_TIME_INT();
 
   preset_cmd = COMMAND_ROLLBACK;
   preset_fd = fd;
   mt_exec(&checkpoint_thread);
 
-  START_TIMERS();
+  RESUME_TIME_INT();
 }
 /*---------------------------------------------------------------------------*/
+static uint8_t inited = 0;
 void
 checkpoint_arch_init(void)
 {
+  if(inited) {
+    return;
+  }
+
   mt_init();
-  mt_start(&checkpoint_thread, thread_loop, NULL);
+  mt_start(&checkpoint_thread, checkpoint_thread_loop, NULL);
+  inited = 1;
+
+#if CHECKPOINT_ROLLBACK_BUTTON
+  process_start(&checkpoint_button_process, NULL);
+#endif /* CHECKPOINT_ROLLBACK_BUTTON */
 
   /*mt_stop(&checkpoint_thread);*/
   /*mt_remove();*/
 }
 /*---------------------------------------------------------------------------*/
+struct power_log {
+  uint32_t transmit;
+  uint32_t listen;
+};
+/*---------------------------------------------------------------------------*/
+#if WITH_SERIAL_COMMANDS
+static void
+serial_interrupt_checkpoint()
+{
+  int fd = 0;
+  PAUSE_TIME();
+
+  if(SPI_IS_ENABLED()) {
+    /* SPI is busy, abort */
+    PRINTF_COMMAND("CP:SPIBUSY\n");
+    RESUME_TIME();
+    return;
+  }
+
+  /* Open file */
+  cfs_remove("cp");
+  cfs_coffee_reserve("cp", checkpoint_arch_size());
+  fd = cfs_open("cp", CFS_WRITE);
+
+  if(fd < 0) {
+    printf("ERROR: No file access (cp)\n");
+    RESUME_TIME();
+    return;
+  }
+
+  /* Checkpoint */
+  preset_cmd = COMMAND_CHECKPOINT;
+  preset_fd = fd;
+  mt_exec(&checkpoint_thread);
+
+  /* Close file */
+  cfs_close(fd);
+
+  RESUME_TIME();
+}
+/*---------------------------------------------------------------------------*/
+static void
+serial_interrupt_rollback()
+{
+  int fd = 0;
+  PAUSE_TIME();
+
+  if(SPI_IS_ENABLED()) {
+    /* SPI is busy, abort */
+    PRINTF_COMMAND("RB:SPIBUSY\n");
+    RESUME_TIME();
+    return;
+  }
+
+  /* Open file */
+  fd = cfs_open("cp", CFS_READ);
+
+  if(fd < 0) {
+    printf("ERROR: No file access (rb)\n");
+    RESUME_TIME();
+    return;
+  }
+
+  /* Rollback */
+  preset_cmd = COMMAND_ROLLBACK;
+  preset_fd = fd;
+  mt_exec(&checkpoint_thread);
+
+  /* Close file */
+  cfs_close(fd);
+
+  RESUME_TIME();
+}
+/*---------------------------------------------------------------------------*/
+static void
+serial_interrupt_metrics()
+{
+  PAUSE_TIME();
+
+  preset_cmd = COMMAND_METRICS;
+  preset_fd = -1;
+  mt_exec(&checkpoint_thread);
+
+  RESUME_TIME();
+}
+/*---------------------------------------------------------------------------*/
+static const unsigned char command_checkpoint[] = { 'c', 'p', '\n' };
+static const unsigned char command_rollback[] = { 'r', 'b', '\n' };
+static const unsigned char command_metrics[] = { 'm', 't', '\n' };
+static volatile int command_checkpoint_state = 0;
+static volatile int command_rollback_state = 0;
+static volatile int command_metrics_state = 0;
+/*---------------------------------------------------------------------------*/
+static int
+serial_input_byte_intercept(unsigned char c)
+{
+  /* Detect checkpoint request */
+  if(command_checkpoint[command_checkpoint_state] == c) {
+    command_checkpoint_state++;
+
+    if(command_checkpoint_state == sizeof(command_checkpoint)) {
+      serial_interrupt_checkpoint();
+      command_checkpoint_state = 0;
+    }
+  } else {
+    command_checkpoint_state = 0;
+  }
+
+  /* Detect rollback request */
+  if(command_rollback[command_rollback_state] == c) {
+    command_rollback_state++;
+
+    if(command_rollback_state == sizeof(command_rollback)) {
+      serial_interrupt_rollback();
+      command_rollback_state = 0;
+    }
+  } else {
+    command_rollback_state = 0;
+  }
+
+  /* Detect metrics request */
+  if(command_metrics[command_metrics_state] == c) {
+    command_metrics_state++;
+
+    if(command_metrics_state == sizeof(command_metrics)) {
+      serial_interrupt_metrics();
+      command_metrics_state = 0;
+    }
+  } else {
+    command_metrics_state = 0;
+  }
+
+  /* Forward to serial line input byte */
+  return serial_line_input_byte(c);
+}
+/*---------------------------------------------------------------------------*/
+static void
+handle_get_command(void)
+{
+  int fd = 0;
+  fd = cfs_open("cp", CFS_READ);
+  if(fd < 0) {
+    printf("ERROR: No file access (get)\n");
+  } else {
+    PRINTF_COMMAND("GET:START\n");
+    char data[8];
+    int offset=0, size=0, read=8;
+    unsigned short crc = 0;
+    cfs_seek(fd, offset, CFS_SEEK_SET);
+
+    while (read == 8) {
+      int i;
+
+      /*if(offset != cfs_seek(fd, offset, CFS_SEEK_SET)) {
+        printf("bad seek, breaking\n");
+        break;
+      }*/
+      read = cfs_read(fd, data, 8);
+      size += read;
+
+      printf("%04i: ", offset); /*REMOVE*/
+      for (i=0; i < read; i++) {
+        crc = crc16_add((uint8_t) data[i], crc);
+        printf("%02x", (uint8_t) (0xff&data[i]));
+      }
+      printf("\n");
+
+      offset += 8;
+    }
+
+    PRINTF_COMMAND("GET:DONE CRC=%u\n", crc);
+    cfs_close(fd);
+  }
+}
+/*---------------------------------------------------------------------------*/
+static int
+hex_decode_char(char c)
+{
+  if(c >= 'A' && c <= 'F') {
+    return c - 'A' + 10;
+  } else if(c >= 'a' && c <= 'f') {
+    return c - 'a' + 10;
+  } else if(c >= '0' && c <= '9') {
+    return c - '0';
+  } else {
+    printf("WARN: bad hex: %c\n", c);
+    return 0;
+  }
+}
+/*---------------------------------------------------------------------------*/
+PROCESS(checkpoint_serial_process, "Checkpoint via serial commands");
+PROCESS_THREAD(checkpoint_serial_process, ev, data)
+{
+  static int set_fd = -1;
+  static int set_count = -1;
+
+  PROCESS_BEGIN();
+
+  /* Note: 'cp', 'rb', and 'mt' commands are intercepted */
+  PROCESS_PAUSE();
+  uart1_set_input(serial_input_byte_intercept);
+
+  /* Format Coffee? */
+  PRINTF("Formatting Coffee\n");
+  cfs_coffee_format();
+  PRINTF("Formatting Coffee... done!\n");
+
+  while(1) {
+    PROCESS_WAIT_EVENT_UNTIL(ev == serial_line_event_message && data != NULL);
+
+    if(strcmp("set", data) == 0) {
+      /* TODO Handle set command */
+      /* Open file */
+      cfs_remove("cp");
+      cfs_coffee_reserve("cp", checkpoint_arch_size());
+      set_fd = cfs_open("cp", CFS_WRITE);
+      set_count = 0;
+      if(set_fd < 0) {
+        printf("SET:FSBUSY\n");
+      } else {
+        printf("SET:LINE\n");
+      }
+    } else if(set_fd >= 0 && strcmp("set:done", data) == 0) {
+        cfs_close(set_fd);
+        set_fd = -1;
+        if(set_count == 9862) {
+          printf("SET:DONE\n");
+        } else {
+          printf("SET:WRONGSIZE\n");
+        }
+    } else if(set_fd >= 0) {
+      /* We are ready for another line */
+      printf("SET:LINE\n");
+      /* Set command: parse hex data */
+      int len = strlen((char*)data);
+      if(len > 16 || (len%2)!=0) {
+        printf("WARN: bad set data: %s\n", (char*)data);
+      } else {
+        int i;
+        for (i=0; i < len; i+=2) {
+          uint8_t b =
+            (hex_decode_char(((char*)data)[i]) << 4) +
+            (hex_decode_char(((char*)data)[i+1]));
+
+          PRINTF("Parsing set command: writing to CFS: %02x\n", b);
+          write_byte(set_fd, b); /* TODO Check return value */
+          set_count++;
+        }
+      }
+    } else if(strcmp("", data) == 0 ||
+        strcmp("cp", data) == 0 ||
+        strcmp("rb", data) == 0 ||
+        strcmp("mt", data) == 0) {
+      /* ignore commands: handled by interrupt */
+    } else if(strcmp("ping", data) == 0) {
+      nr_pongs++;
+      printf("pong %u\n", nr_pongs);
+    } else if(strcmp("get", data) == 0) {
+      handle_get_command();
+    } else {
+      printf("WARN: Unknown command: '%s'\n", (char*)data);
+    }
+  }
+
+  PROCESS_END();
+}
+#endif /* WITH_SERIAL_COMMANDS */
+/*---------------------------------------------------------------------------*/
+#if CHECKPOINT_ROLLBACK_BUTTON
+PROCESS_THREAD(checkpoint_button_process, ev, data)
+{
+  PROCESS_BEGIN();
+
+  button_sensor.configure(SENSORS_ACTIVE, 1);
+
+  while(1) {
+    PROCESS_WAIT_EVENT();
+
+    if(ev == sensors_event && data == &button_sensor) {
+      int fd = 0;
+
+      /* Rollback from Coffee file "cp_wdt" */
+      fd = cfs_open("cp_wdt", CFS_READ);
+      if(fd >= 0) {
+        checkpoint_rollback(fd);
+        cfs_close(fd);
+      }
+    }
+  }
+
+  PROCESS_END();
+}
+#endif /* CHECKPOINT_ROLLBACK_BUTTON */