Rewrote the default powertrace_sniff() behaviour. Instead of printing

out power data for all incoming and outgoing packets (which causes
problems when there is much traffic), the power data for the packets
is instead logged and periodically printed out in aggregated form.

apps/powertrace/powertrace.c

@@ -28,7 +28,7 @@
  *
  * This file is part of the Contiki operating system.
  *
- * $Id: powertrace.c,v 1.6 2010/04/30 07:17:21 adamdunkels Exp $
+ * $Id: powertrace.c,v 1.7 2010/09/22 22:09:52 adamdunkels Exp $
  */
 
 /**
@@ -39,13 +39,29 @@
  */
 
 #include "contiki.h"
+#include "contiki-lib.h"
 #include "sys/compower.h"
-#include "node-id.h"
 #include "powertrace.h"
 #include "net/rime.h"
-#include "node-id.h"
 
 #include <stdio.h>
+#include <string.h>
+
+struct powertrace_sniff_stats {
+  struct powertrace_sniff_stats *next;
+  uint32_t num_input, num_output;
+  uint32_t input_txtime, input_rxtime;
+  uint32_t output_txtime, output_rxtime;
+  uint16_t channel;
+};
+
+#define INPUT  1
+#define OUTPUT 0
+
+#define MAX_NUM_STATS  16
+
+MEMB(stats_memb, struct powertrace_sniff_stats, MAX_NUM_STATS);
+LIST(stats_list);
 
 PROCESS(powertrace_process, "Periodic power output");
 /*---------------------------------------------------------------------------*/
@@ -59,11 +75,12 @@ powertrace_print(char *str)
   static uint32_t idle_transmit, idle_listen;
 
   static uint32_t seqno;
-  
+
-  uint32_t time;
+  uint32_t time, total_radio;
+  struct powertrace_sniff_stats *s;
 
   energest_flush();
-  
+
   cpu = energest_type_time(ENERGEST_TYPE_CPU) - last_cpu;
   lpm = energest_type_time(ENERGEST_TYPE_LPM) - last_lpm;
   transmit = energest_type_time(ENERGEST_TYPE_TRANSMIT) - last_transmit;
@@ -79,10 +96,12 @@ powertrace_print(char *str)
   last_idle_transmit = compower_idle_activity.transmit;
 
   time = cpu + lpm;
-  
+  total_radio = energest_type_time(ENERGEST_TYPE_LISTEN) +
-  printf("%s %lu P %d %lu %lu %lu %lu %lu %lu %lu (radio %d.%02d%% tx %d.%02d%% listen %d.%02d%%)\n",
+    energest_type_time(ENERGEST_TYPE_TRANSMIT);
+
+  printf("%s %lu P %d.%d %lu %lu %lu %lu %lu %lu %lu (radio %d.%02d%% tx %d.%02d%% listen %d.%02d%%)\n",
          str,
-         clock_time(), node_id, seqno++,
+         clock_time(), rimeaddr_node_addr.u8[0], rimeaddr_node_addr.u8[1], seqno,
          cpu, lpm, transmit, listen, idle_transmit, idle_listen,
          (int)((100L * (transmit + listen)) / time),
          (int)((10000L * (transmit + listen) / time) - (100L * (transmit + listen) / time) * 100),
@@ -90,6 +109,18 @@ powertrace_print(char *str)
          (int)((10000L * transmit) / time - (100L * transmit / time) * 100),
          (int)((100L * listen) / time),
          (int)((10000L * listen) / time - (100L * listen / time) * 100));
+
+  for(s = list_head(stats_list); s != NULL; s = list_item_next(s)) {
+    printf("%s %lu SP %d.%d %lu %u %lu %lu %lu %lu %lu %lu (channel %d radio %d.%02d%%)\n",
+           str, clock_time(), rimeaddr_node_addr.u8[0], rimeaddr_node_addr.u8[1], seqno,
+           s->channel,
+           s->num_input, s->input_txtime, s->input_rxtime,
+           s->num_output, s->output_txtime, s->output_rxtime,
+           s->channel,
+           (int)((100L * (s->input_rxtime + s->input_txtime + s->output_rxtime + s->output_txtime)) / total_radio),
+           (int)((10000L * (s->input_rxtime + s->input_txtime + s->output_rxtime + s->output_txtime)) / total_radio));
+  }
+  seqno++;
 }
 /*---------------------------------------------------------------------------*/
 PROCESS_THREAD(powertrace_process, ev, data)
@@ -150,15 +181,70 @@ sniffprint(char *prefix, int seqno)
 }
 /*---------------------------------------------------------------------------*/
 static void
+add_stats(struct powertrace_sniff_stats *s, int input_or_output)
+{
+  if(input_or_output == INPUT) {
+    s->num_input++;
+    s->input_txtime += packetbuf_attr(PACKETBUF_ATTR_TRANSMIT_TIME);
+    s->input_rxtime += packetbuf_attr(PACKETBUF_ATTR_LISTEN_TIME);
+  } else if(input_or_output == OUTPUT) {
+    s->num_output++;
+    s->output_txtime += packetbuf_attr(PACKETBUF_ATTR_TRANSMIT_TIME);
+    s->output_rxtime += packetbuf_attr(PACKETBUF_ATTR_LISTEN_TIME);
+  }
+}
+/*---------------------------------------------------------------------------*/
+static void
+add_packet_stats(int input_or_output)
+{
+  struct powertrace_sniff_stats *s;
+
+  if(packetbuf_attr(PACKETBUF_ATTR_CHANNEL) == 0) {
+    printf("Channel 0\n");
+  }
+  
+  /* Go through the list of stats to find one that matches the channel
+     of the packet. If we don't find one, we allocate a new one and
+     put it on the list. */
+  for(s = list_head(stats_list); s != NULL; s = list_item_next(s)) {
+    if(s->channel == packetbuf_attr(PACKETBUF_ATTR_CHANNEL)) {
+      add_stats(s, input_or_output);
+      break;
+    }
+  }
+  if(s == NULL) {
+    s = memb_alloc(&stats_memb);
+    if(s != NULL) {
+      memset(s, 0, sizeof(struct powertrace_sniff_stats));
+      s->channel = packetbuf_attr(PACKETBUF_ATTR_CHANNEL);
+      list_add(stats_list, s);
+      add_stats(s, input_or_output);
+    }
+  }
+}
+/*---------------------------------------------------------------------------*/
+static void
 input_sniffer(void)
 {
-  static int seqno = 0;
+  add_packet_stats(INPUT);
+}
+/*---------------------------------------------------------------------------*/
+static void
+output_sniffer(void)
+{
+  add_packet_stats(OUTPUT);
+}
+/*---------------------------------------------------------------------------*/
+static void
+input_printsniffer(void)
+{
+  static int seqno = 0; 
   sniffprint("I", seqno++);
 
   if(packetbuf_attr(PACKETBUF_ATTR_CHANNEL) == 0) {
     int i;
     uint8_t *dataptr;
-    
+
     printf("x %d ", packetbuf_totlen());
     dataptr = packetbuf_hdrptr();
     printf("%02x ", dataptr[0]);
@@ -170,23 +256,37 @@ input_sniffer(void)
 }
 /*---------------------------------------------------------------------------*/
 static void
-output_sniffer(void)
+output_printsniffer(void)
 {
   static int seqno = 0;
   sniffprint("O", seqno++);
 }
 /*---------------------------------------------------------------------------*/
-RIME_SNIFFER(s, input_sniffer, output_sniffer);
+RIME_SNIFFER(powersniff, input_sniffer, output_sniffer);
+RIME_SNIFFER(printsniff, input_printsniffer, output_printsniffer);
 /*---------------------------------------------------------------------------*/
 void
 powertrace_sniff(powertrace_onoff_t onoff)
 {
   switch(onoff) {
   case POWERTRACE_ON:
-    rime_sniffer_add(&s);
+    rime_sniffer_add(&powersniff);
     break;
   case POWERTRACE_OFF:
-    rime_sniffer_remove(&s);
+    rime_sniffer_remove(&powersniff);
+    break;
+  }
+}
+/*---------------------------------------------------------------------------*/
+void
+powertrace_printsniff(powertrace_onoff_t onoff)
+{
+  switch(onoff) {
+  case POWERTRACE_ON:
+    rime_sniffer_add(&printsniff);
+    break;
+  case POWERTRACE_OFF:
+    rime_sniffer_remove(&printsniff);
     break;
   }
 }