Re: [PATCH] host/dump_instr : support for byteswapping, real time, wrapped buffers

["Pieter-Jan Busschaert" <pieterjan.busschaert@gmail.com>]

[-- Attachment #1: Type: text/plain, Size: 1077 bytes --]

I made 2 small modifications to the previous patch :

*) print time with more digits (to facilitate processing the output as
fixed-width columns)
*) if first clock tick not found, initialize time to 0 ms

diff to previously posted patch :

%------------------------------
--- ecos/packages/kernel/current/host/instr/dump_instr.c.patch1
2007-10-12 11:02:12.000000000 +0200
+++ ecos/packages/kernel/current/host/instr/dump_instr.c.patch2
2007-10-12 10:49:06.000000000 +0200
@@ -156,7 +156,7 @@
       printf("%4d Record type 0x%04x, thread %2d, ",
              cnt, record.type, record.thread);
 #endif
-      printf("time %10lld, arg1 0x%08x, arg2 0x%08x\n",
+      printf("time %12lld, arg1 0x%08x, arg2 0x%08x\n",
              cvt_time(record.timestamp), record.arg1,
              record.arg2);

@@ -170,6 +170,7 @@

   if (findfirstclock) {
     printf("first tick not found\r\n");
+    ticks = 0;
   }
 }

%----------------------------

Because the previous patch was not applied (yet), the full diff to
latest version in anoncvs is attached too.


Pieter-Jan Busschaert

[-- Attachment #2: dump_instr.diff --]
[-- Type: application/octet-stream, Size: 5981 bytes --]

--- ecos/packages/kernel/current/host/instr/dump_instr.c	2007-08-17 13:47:40.000000000 +0200
+++ ecos/packages/kernel/current/host/instr/dump_instr.c	2007-10-12 10:49:06.000000000 +0200
@@ -4,6 +4,11 @@
 
 #include <stdio.h>
 #include <stdlib.h>
+#include <stdint.h>
+#include <unistd.h>
+
+#define CYG_INSTRUMENT_CLOCK_TICK_START (CYG_INSTRUMENT_EVENT_CLOCK_TICK_START|CYG_INSTRUMENT_CLASS_CLOCK)
+#define CYG_INSTRUMENT_CLOCK_ISR (CYG_INSTRUMENT_EVENT_CLOCK_ISR|CYG_INSTRUMENT_CLASS_CLOCK)
 
 // -------------------------------------------------------------------------
 // Instrumentation record.
@@ -19,6 +24,12 @@
 
 // -------------------------------------------------------------------------
 
+static long rtc_resolution[] = CYGNUM_KERNEL_COUNTERS_RTC_RESOLUTION;
+static CYG_WORD64 ns_per_tick;
+static CYG_WORD64 ps_per_hal_clock;
+static CYG_WORD64 ticks = -1;
+static bool swapbytes = false;
+
 #ifdef CYGDBG_KERNEL_INSTRUMENT_MSGS
 #define CYGDBG_KERNEL_INSTRUMENT_MSGS_DEFINE_TABLE
 #include <cyg/kernel/instrument_desc.h>
@@ -55,8 +66,112 @@
 
 void usage(char *myname) 
 {
-  fprintf(stderr,"Usage: %s <filename>\n",myname);
-  fprintf(stderr,"where filename is that of the instrumentation data");
+  fprintf(stderr,"Usage: %s [-s] [-w <wrap>] <filename>\n",myname);
+  fprintf(stderr,"where filename is that of the instrumentation data\n");
+  fprintf(stderr,"add -s to enable byteswapping\n");
+  fprintf(stderr,"<wrap> = oldest item in case of a wrapped buffer\n");
+}
+
+uint16_t swap2bytes(uint16_t input)
+{
+  uint16_t result = 0;
+  result += (input & 0xff00) >> 8;
+  result += (input & 0x00ff) << 8;
+  return result;
+}
+
+uint32_t swap4bytes(uint32_t input)
+{
+  uint32_t result = 0;
+  result += (input & 0xff000000) >> 24;
+  result += (input & 0x00ff0000) >> 8;
+  result += (input & 0x0000ff00) << 8;
+  result += (input & 0x000000ff) << 24;
+  return result;
+}
+
+/* Return the time in ns */
+CYG_WORD64 cvt_time(CYG_WORD timestamp) 
+{
+  return (  (ticks * ns_per_tick) + 
+            ((CYG_WORD64)timestamp * ps_per_hal_clock) / 1000);
+}
+
+void scan_file(FILE* file, int firstitem, bool findfirstclock)
+{
+  struct Instrument_Record record;
+  bool wrapped = false;
+
+  fseek(file, sizeof(record)*firstitem, SEEK_SET);
+  int cnt = firstitem;
+
+  while (!feof(file)) {
+    if (fread(&record,sizeof(record),1,file) == 0) {    // EOF reached, wrap around
+      if (!wrapped) {
+        fseek(file, 0, SEEK_SET);
+        cnt = 0;
+        wrapped = true;
+        continue;
+      }
+      break;
+    }
+
+    if (wrapped && cnt == firstitem) {                  // end of buffer reached
+      break;
+    }
+
+    if (record.type == 0) {
+      break;
+    }
+    
+    if (swapbytes) {
+      record.type = swap2bytes(record.type);
+      record.thread = swap2bytes(record.thread);
+      record.timestamp = swap4bytes(record.timestamp);
+      record.arg1 = swap4bytes(record.arg1);
+      record.arg2 = swap4bytes(record.arg2);
+    }
+
+    if (record.type == CYG_INSTRUMENT_CLOCK_TICK_START) {
+      if (findfirstclock) {
+        ticks = ((CYG_WORD64)record.arg2 << 32) + ((CYG_WORD64)record.arg1);
+        printf("first tick found on item %d => %d\r\n", cnt, ticks);
+        ticks--;
+        return;
+      } else {
+        if (ticks != ((CYG_WORD64)record.arg2 << 32) + ((CYG_WORD64)record.arg1)) {
+          printf("tick count error : ticks = %lld, should be %lld\r\n", 
+                 ticks, ((CYG_WORD64)record.arg2 << 32) + ((CYG_WORD64)record.arg1));
+          ticks = ((CYG_WORD64)record.arg2 << 32) + ((CYG_WORD64)record.arg1);
+        }
+      }
+    }
+
+    if (!findfirstclock) {
+#ifdef CYGDBG_KERNEL_INSTRUMENT_MSGS 
+      printf("%4d Record type (0x%04x): %-20s thread %2d, ",
+             cnt, record.type, cyg_instrument_msg(record.type), 
+             record.thread);
+#else
+      printf("%4d Record type 0x%04x, thread %2d, ",
+             cnt, record.type, record.thread);
+#endif
+      printf("time %12lld, arg1 0x%08x, arg2 0x%08x\n",
+             cvt_time(record.timestamp), record.arg1,
+             record.arg2);
+
+      if (record.type == CYG_INSTRUMENT_CLOCK_ISR) {
+        ticks++;
+      }
+    }
+
+    cnt++;
+  }
+
+  if (findfirstclock) {
+    printf("first tick not found\r\n");
+    ticks = 0;
+  }
 }
 
 int main(int argc, char * argv[]) 
@@ -66,13 +181,40 @@
   char * filename;
   struct Instrument_Record record;
   int cnt=0;
+  int firstitem = 0;
+  bool wrapped = false;
+  int c;
+
+  ns_per_tick = rtc_resolution[0]/rtc_resolution[1];
+  ps_per_hal_clock = ns_per_tick * 1000 / CYGNUM_KERNEL_COUNTERS_RTC_PERIOD;
+
+  while ((c = getopt(argc, argv, "sw:")) != -1) {
+    switch (c) {
+    case 's':
+      swapbytes = true;
+      break;
+    case 'w':
+      firstitem = atoi(optarg);
+      break;
+    case '?':
+      if (isprint(optopt)) {
+        fprintf (stderr, "Unknown option '-%c'.\n", optopt);
+      } else {
+        fprintf (stderr, "Unknown option '\\x%x'.\n", optopt);
+      }
+      
+      return 1;
+    default:
+      abort ();
+    }
+  }
 
-  if (argc != 2) {
+  if ((argc - optind) != 1) {
     usage(argv[0]);
     exit(1);
   }
 
-  filename = argv[1];
+  filename = argv[optind];
 
   file = fopen(filename, "r");
   if (!file) {
@@ -81,24 +223,8 @@
     exit(1);
   }
   
-  while (!feof(file)) {
-    fread(&record,sizeof(record),1,file);
-    if (record.type == 0) {
-      break;
-    }
-
-#ifdef CYGDBG_KERNEL_INSTRUMENT_MSGS 
-    printf("%4d Record type (0x%04x): %-20s thread %2d, ",
-           cnt++,record.type,cyg_instrument_msg(record.type), 
-           record.thread);
-#else
-    printf("%4d Record type 0x%04x, thread %2d, ",
-           cnt++,record.type, record.thread);
-#endif
-    printf("time %5d, arg1 0x%08x, arg2 0x%08x\n",
-           record.timestamp, record.arg1,
-           record.arg2);
-  }
+  scan_file(file, firstitem, true);
+  scan_file(file, firstitem, false);
 
   fclose(file);
   return (0);