From: Jack Lange <jarusl@cs.northwestern.edu>
Date: Mon, 9 Feb 2009 19:20:29 +0000 (-0600)
Subject: cleaned up instrumentation implementation
X-Git-Url: http://v3vee.org/palacios/gitweb/gitweb.cgi?p=palacios.git;a=commitdiff_plain;h=0e1c2f1eb7e964848d43824328205d5557bc7639

cleaned up instrumentation implementation
---

diff --git a/palacios/build/Makefile b/palacios/build/Makefile
index 8fbe2a2..0f98a56 100644
--- a/palacios/build/Makefile
+++ b/palacios/build/Makefile
@@ -219,8 +219,14 @@ endif
 
 ifeq ($(INSTRUMENT_VMM),1)
   EXTRA_C_OPTS:= -DINSTRUMENT_VMM
+  INSTRUMENT_OPT := -finstrument-functions
+  OBJ_FILES := palacios/vmm_instrument.o
+else
+  INSTRUMENT_OPT := 
 endif
 
+
+
 # ----------------------------------------------------------------------
 # Configuration -
 #   Various options specifying how GeekOS should be built,
@@ -273,7 +279,7 @@ VMM_OBJS := \
 	palacios/vmm_profiler.o \
 	palacios/vmm_direct_paging.o \
 	palacios/vmm_ringbuffer.o \
-	palacios/vmm_instrument.o \
+	$(OBJ_FILES)
 
 #		vmx.c vmcs_gen.c vmcs.c
 
@@ -407,11 +413,6 @@ CC_GENERAL_OPTS = \
 #-fPIC \
 #-fvisibility=hidden
 
-ifeq ($(INSTRUMENT_VMM),1)
-	INSTRUMENT_OPT = -finstrument-functions
-else
-	INSTRUMENT_OPT = 
-endif
 
 # Flags passed to objcopy program (strip unnecessary sections from kernel.exe)
 OBJCOPY_FLAGS := -R .dynamic -R .note -R .comment
diff --git a/palacios/include/palacios/vmm_instrument.h b/palacios/include/palacios/vmm_instrument.h
index f9e1176..b59eac0 100644
--- a/palacios/include/palacios/vmm_instrument.h
+++ b/palacios/include/palacios/vmm_instrument.h
@@ -27,22 +27,8 @@
 #include <palacios/vmm_types.h>
 #include <palacios/vmm_ringbuffer.h>
 
-ullong_t now, last;
-
-int instrument_start;
-
-struct Inst_RingBuff *ring_buff;
-
-struct PackData *pack_data;
-
-void __attribute__((__no_instrument_function__)) v3_init_cyg_profiler ();
- 
-void __attribute__((__no_instrument_function__))
-__cyg_profile_func_enter( void *this, void *callsite );
- 
-void __attribute__((__no_instrument_function__)) 
-__cyg_profile_func_exit( void *this, void *callsite );
 
+void v3_init_instrumentation() __attribute__((__no_instrument_function__));
 
 #endif // INSTRUMENT_VMM
 
diff --git a/palacios/include/palacios/vmm_ringbuffer.h b/palacios/include/palacios/vmm_ringbuffer.h
index 29e892f..dec11c9 100644
--- a/palacios/include/palacios/vmm_ringbuffer.h
+++ b/palacios/include/palacios/vmm_ringbuffer.h
@@ -24,6 +24,11 @@
 
 #include <palacios/vmm_types.h>
 
+#ifdef INSTRUMENT_VMM
+#define NO_INST __attribute__((__no_instrument_function__))
+#else 
+#define NO_INST 
+#endif
 
 struct v3_ringbuf {
   uchar_t * buf;
@@ -35,20 +40,20 @@ struct v3_ringbuf {
 };
 
 
-void v3_init_ringbuf(struct v3_ringbuf * ring, uint_t size);
-struct v3_ringbuf * v3_create_ringbuf(uint_t size);
-void v3_free_ringbuf(struct v3_ringbuf * ring);
-
+void v3_init_ringbuf(struct v3_ringbuf * ring, uint_t size) NO_INST;
+struct v3_ringbuf * v3_create_ringbuf(uint_t size) NO_INST;
+void v3_free_ringbuf(struct v3_ringbuf * ring) NO_INST;
 
-int v3_ringbuf_read(struct v3_ringbuf * ring, uchar_t * dst, uint_t len);
-int v3_ringbuf_peek(struct v3_ringbuf * ring, uchar_t * dst, uint_t len);
-int v3_ringbuf_delete(struct v3_ringbuf * ring, uint_t len);
-int v3_ringbuf_write(struct v3_ringbuf * ring, uchar_t * src, uint_t len);
-int v3_ringbuf_data_len(struct v3_ringbuf * ring);
-int v3_ringbuf_capacity(struct v3_ringbuf * ring);
 
+int v3_ringbuf_read(struct v3_ringbuf * ring, uchar_t * dst, uint_t len) NO_INST;
+int v3_ringbuf_peek(struct v3_ringbuf * ring, uchar_t * dst, uint_t len) NO_INST;
+int v3_ringbuf_delete(struct v3_ringbuf * ring, uint_t len) NO_INST;
+int v3_ringbuf_write(struct v3_ringbuf * ring, uchar_t * src, uint_t len) NO_INST;
+int v3_ringbuf_data_len(struct v3_ringbuf * ring) NO_INST;
+int v3_ringbuf_capacity(struct v3_ringbuf * ring) NO_INST;
+int v3_ringbuf_avail_space(struct v3_ringbuf * ring) NO_INST;
 
-void v3_print_ringbuf(struct v3_ringbuf * ring);
+void v3_print_ringbuf(struct v3_ringbuf * ring) NO_INST;
 
 
 #endif
diff --git a/palacios/src/palacios/vmm.c b/palacios/src/palacios/vmm.c
index 8459e4c..77c654e 100644
--- a/palacios/src/palacios/vmm.c
+++ b/palacios/src/palacios/vmm.c
@@ -44,9 +44,9 @@ void Init_V3(struct v3_os_hooks * hooks, struct v3_ctrl_ops * vmm_ops) {
 
   v3_cpu_type = V3_INVALID_CPU;
 
-	#ifdef INSTRUMENT_VMM
-	    v3_init_cyg_profiler();
-	#endif
+#ifdef INSTRUMENT_VMM
+  v3_init_instrumentation();
+#endif
 
   if (v3_is_svm_capable()) {
 
diff --git a/palacios/src/palacios/vmm_instrument.c b/palacios/src/palacios/vmm_instrument.c
index e67f818..a207455 100644
--- a/palacios/src/palacios/vmm_instrument.c
+++ b/palacios/src/palacios/vmm_instrument.c
@@ -17,77 +17,120 @@
  * redistribute, and modify it as specified in the file "V3VEE_LICENSE".
  */
 
-#ifdef INSTRUMENT_VMM
- 
+#ifdef INSTRUMENT_VMM 
+
 #include <palacios/svm_handler.h>
 #include <palacios/vmm_instrument.h>
+
+#define NO_INSTRUMENTATION
 #include <palacios/vmm_ringbuffer.h>
- 
-void __attribute__((__no_instrument_function__)) v3_init_cyg_profiler (){
+#undef NO_INSTRUMENTATION
+
+#define RING_SIZE 2000
+
+static ullong_t last = 0;
+static struct v3_ringbuf * func_ring = NULL;
+
+struct instrumented_func {
+  ullong_t time; 
+  uint_t exiting;
+  void * called_fn;
+  void * calling_fn;
+} __attribute__((packed));
+
+
 
-// initialize
+static void print_instrumentation()  __attribute__((__no_instrument_function__));
 
-	v3_Inst_RingBuff_init (&ring_buff, 2048); //dequeue at every 4095
-	
-	instrument_start = 1;
-	
+void __cyg_profile_func_enter(void * this, void * callsite)   __attribute__((__no_instrument_function__));
+void __cyg_profile_func_exit(void * this, void * callsite)   __attribute__((__no_instrument_function__));
+
+void v3_init_instrumentation() {
+  PrintDebug("Creating Ring Buffer (unit size = %d)\n", (uint_t)sizeof(struct instrumented_func));
+  // initialize
+  func_ring = v3_create_ringbuf(sizeof(struct instrumented_func) * RING_SIZE); //dequeue at every 4095  
 }
 
-static void inline __attribute__((__no_instrument_function__)) read_cyg_profiler (){
 
-		while( v3_Inst_RingBuff_data_size(ring_buff) > 0) {
 
-		v3_Inst_RingBuff_read (ring_buff, pack_data, 1); 
-		PrintDebug("CYG_PROF: %d %8lu %08x %08x\n", pack_data->state, (unsigned long)pack_data->time, pack_data->cur_fn, pack_data->pre_fn);	
-	
-		}	
+ __attribute__((__no_instrument_function__))
+void __cyg_profile_func_enter(void * this, void * callsite) {
+
+  if (func_ring != NULL) {
+
+    struct instrumented_func tmp_fn;
+    ullong_t now = 0; 
+
+    rdtscll(now);
+
+    //PrintDebug("Entering Function\n");
+
+    if (v3_ringbuf_avail_space(func_ring) < sizeof(struct instrumented_func)) {
+      print_instrumentation();
+    }
+    
+    tmp_fn.time = now - last; // current tsc
+    tmp_fn.exiting = 0; //enter to be 0
+    tmp_fn.called_fn = this; //this
+    tmp_fn.calling_fn = callsite; //callsite
+    
+    //    PrintDebug("Writing Function: fn_data=%p, size=%d\n", 
+    //       (void *)&tmp_fn, (uint_t)sizeof(struct instrumented_func));
+    v3_ringbuf_write(func_ring, (uchar_t *)&tmp_fn, sizeof(struct instrumented_func));  
+
+    rdtscll(last);
+  }
 }
 
-void __attribute__((__no_instrument_function__))
-__cyg_profile_func_enter( void *this, void *callsite )
-{
-		
-	if(instrument_start > 0) {
-
-	rdtscll(now);
-  	
-	if((v3_Inst_RingBuff_data_size(ring_buff) % 500) == 0 || v3_Inst_RingBuff_data_size(ring_buff) == 4095) {
-	read_cyg_profiler();
-	}
-  
-  
-  pack_data->time = now - last; //time spent previous
-  pack_data->state = 0; //enter to be 0
-  pack_data->cur_fn = (unsigned int)this; //this
-  pack_data->pre_fn = (unsigned int)callsite; //callsite
-
-	v3_Inst_RingBuff_write (ring_buff, pack_data, 1);  
-
-  rdtscll(now);
-  last = now;
-	}
+
+ __attribute__((__no_instrument_function__))
+void __cyg_profile_func_exit(void * this, void * callsite){
+
+  if (func_ring != NULL) {
+
+    struct instrumented_func tmp_fn;
+    ullong_t now = 0;
+
+    rdtscll(now);
+    
+    //    PrintDebug("Exiting Function\n");
+
+    if (v3_ringbuf_avail_space(func_ring) < sizeof(struct instrumented_func)) {
+      print_instrumentation();
+    }
+    
+    tmp_fn.time = now - last; // current tsc
+    tmp_fn.exiting = 1; //exit to be 0
+    tmp_fn.called_fn = this; //this
+    tmp_fn.calling_fn = callsite; //callsite
+
+    //    PrintDebug("Writing Function: fn_data=%p, size=%d\n", 
+    //       (void *)&tmp_fn, (uint_t)sizeof(struct instrumented_func));    
+    v3_ringbuf_write(func_ring, (uchar_t *)&tmp_fn, sizeof(struct instrumented_func));
+    
+    rdtscll(last);
+  }
 }
 
-void __attribute__((__no_instrument_function__)) 
-__cyg_profile_func_exit( void *this, void *callsite )
-{
-	if(instrument_start > 0 ) {
-	rdtscll(now);
-
-	if((v3_Inst_RingBuff_data_size(ring_buff) % 500) == 0 || v3_Inst_RingBuff_data_size(ring_buff) == 4095) {
-	read_cyg_profiler();
-	}
-  
-  pack_data->time = now - last; //time spent previous
-  pack_data->state = 1; //exit to be 0
-  pack_data->cur_fn = (unsigned int)this; //this
-  pack_data->pre_fn = (unsigned int)callsite; //callsite
-  
-  v3_Inst_RingBuff_write (ring_buff, pack_data, 1);
-  
-  rdtscll(now);
-  last = now;
-	}
+
+
+static void print_instrumentation() {
+
+  struct instrumented_func tmp_fn;
+
+  //  PrintDebug("Printing Instrumentation\n");
+  while (v3_ringbuf_data_len(func_ring) >= sizeof(struct instrumented_func)) {
+    
+    v3_ringbuf_read(func_ring, (uchar_t *)&tmp_fn, sizeof(struct instrumented_func)); 
+    
+    PrintDebug("CYG_PROF: %d %p %p %p\n", 
+	       tmp_fn.exiting, 
+	       (void *)(addr_t)(tmp_fn.time), 
+	       tmp_fn.called_fn, 
+	       tmp_fn.calling_fn);
+  }
 }
 
+
+
 #endif
diff --git a/palacios/src/palacios/vmm_ringbuffer.c b/palacios/src/palacios/vmm_ringbuffer.c
index bbde628..5df142b 100644
--- a/palacios/src/palacios/vmm_ringbuffer.c
+++ b/palacios/src/palacios/vmm_ringbuffer.c
@@ -21,7 +21,9 @@
 #include <palacios/vmm.h>
 
 
-void v3_init_ringbuf(struct v3_ringbuf * ring, uint_t size) {
+
+
+void NO_INST v3_init_ringbuf(struct v3_ringbuf * ring, uint_t size) {
   ring->buf = V3_Malloc(size);
   ring->size = size;
   
@@ -30,7 +32,7 @@ void v3_init_ringbuf(struct v3_ringbuf * ring, uint_t size) {
   ring->current_len = 0;
 }
 
-
+NO_INST 
 struct v3_ringbuf * v3_create_ringbuf(uint_t size) {
   struct v3_ringbuf * ring = (struct v3_ringbuf *)V3_Malloc(sizeof(struct v3_ringbuf));
 
@@ -39,32 +41,34 @@ struct v3_ringbuf * v3_create_ringbuf(uint_t size) {
   return ring;
 }
 
+NO_INST 
 void v3_free_ringbuf(struct v3_ringbuf * ring) {
   V3_Free(ring->buf);
   V3_Free(ring);
 }
 
 
-
-
-
+NO_INST 
 static inline uchar_t * get_read_ptr(struct v3_ringbuf * ring) {
   return (uchar_t *)(ring->buf + ring->start);
 }
 
+NO_INST 
 static inline uchar_t * get_write_ptr(struct v3_ringbuf * ring) {
   return (uchar_t *)(ring->buf + ring->end);
 }
 
-
+NO_INST 
 static inline int get_read_section_size(struct v3_ringbuf * ring) {
   return ring->size - ring->start;
 }
 
+NO_INST 
 static inline int get_write_section_size(struct v3_ringbuf * ring) {
   return ring->size - ring->end;
 }
 
+NO_INST 
 static inline int is_read_loop(struct v3_ringbuf * ring, uint_t len) {
   if ((ring->start >= ring->end) && (ring->current_len > 0)) {
     // end is past the end of the buffer
@@ -75,7 +79,7 @@ static inline int is_read_loop(struct v3_ringbuf * ring, uint_t len) {
   return 0;
 }
 
-
+NO_INST 
 static inline int is_write_loop(struct v3_ringbuf * ring, uint_t len) {
   if ((ring->end >= ring->start) && (ring->current_len < ring->size)) {
     // end is past the end of the buffer
@@ -86,15 +90,22 @@ static inline int is_write_loop(struct v3_ringbuf * ring, uint_t len) {
   return 0;
 }
 
+NO_INST 
+int v3_ringbuf_avail_space(struct v3_ringbuf * ring) {
+  return ring->size - ring->current_len;
+}
 
+ NO_INST 
 int v3_ringbuf_data_len(struct v3_ringbuf * ring) {
   return ring->current_len;
 }
 
+ NO_INST 
 int v3_ringbuf_capacity(struct v3_ringbuf * ring) {
   return ring->size;
 }
 
+NO_INST 
 int v3_ringbuf_read(struct v3_ringbuf * ring, uchar_t * dst, uint_t len) {
   int read_len = 0;
   int ring_data_len = ring->current_len;
@@ -120,8 +131,7 @@ int v3_ringbuf_read(struct v3_ringbuf * ring, uchar_t * dst, uint_t len) {
 }
 
 
-
-
+ NO_INST 
 int v3_ringbuf_peek(struct v3_ringbuf * ring, uchar_t * dst, uint_t len) {
   int read_len = 0;
   int ring_data_len = ring->current_len;
@@ -141,6 +151,7 @@ int v3_ringbuf_peek(struct v3_ringbuf * ring, uchar_t * dst, uint_t len) {
 }
 
 
+NO_INST 
 int v3_ringbuf_delete(struct v3_ringbuf * ring, uint_t len) {
   int del_len = 0;
   int ring_data_len = ring->current_len;
@@ -159,6 +170,7 @@ int v3_ringbuf_delete(struct v3_ringbuf * ring, uint_t len) {
 }
 
 
+NO_INST 
 int v3_ringbuf_write(struct v3_ringbuf * ring, uchar_t * src, uint_t len) {
   int write_len = 0;
   int ring_avail_space = ring->size - ring->current_len;
@@ -168,6 +180,9 @@ int v3_ringbuf_write(struct v3_ringbuf * ring, uchar_t * src, uint_t len) {
 
   if (is_write_loop(ring, write_len)) {
     int section_len = get_write_section_size(ring);
+
+    //  PrintDebug("Write loop: write_ptr=%p, src=%p, sec_len=%d\n", 
+    //	       (void *)get_write_ptr(ring),(void*)src, section_len);
     
     memcpy(get_write_ptr(ring), src, section_len);
     ring->end = 0;
@@ -176,6 +191,9 @@ int v3_ringbuf_write(struct v3_ringbuf * ring, uchar_t * src, uint_t len) {
 
     ring->end += write_len - section_len;
   } else {
+    //    PrintDebug("Writing: write_ptr=%p, src=%p, write_len=%d\n", 
+    //	       (void *)get_write_ptr(ring),(void*)src, write_len);
+
     memcpy(get_write_ptr(ring), src, write_len);
 
     ring->end += write_len;
@@ -187,6 +205,7 @@ int v3_ringbuf_write(struct v3_ringbuf * ring, uchar_t * src, uint_t len) {
 }
 
 
+NO_INST 
 void v3_print_ringbuf(struct v3_ringbuf * ring) {
   int ctr = 0;