trying to introduce cumulative time

git-svn-id: http://ltt.polymtl.ca/svn@1739 04897980-b3bd-0310-b5e0-8ef037075253

diff --git a/ltt/branches/poly/lttv/lttv/state.c b/ltt/branches/poly/lttv/lttv/state.c
index 43b4d7ea9fdfc94fda1256913815d7dfee14e771..8e80c943f462d48a11370f36af8949ab82919aa9 100644 (file)
--- a/ltt/branches/poly/lttv/lttv/state.c
+++ b/ltt/branches/poly/lttv/lttv/state.c
@@ -1045,10 +1045,33 @@ static void push_state(LttvTracefileState *tfs, LttvExecutionMode t,
   es->t = t;
   es->n = state_id;
   es->entry = es->change = tfs->parent.timestamp;
+       es->cum_cpu_time = ltt_time_zero;
   es->s = process->state->s;
   process->state = es;
 }
 
+/* pop state
+ * return 1 when empty, else 0 */
+int lttv_state_pop_state_cleanup(LttvProcessState *process, 
+               LttvTracefileState *tfs)
+{ 
+       guint cpu = tfs->cpu;
+  LttvTraceState *ts = (LttvTraceState*)tfs->parent.t_context;
+
+  guint depth = process->execution_stack->len;
+
+  if(depth == 1){
+    return 1;
+  }
+
+  process->execution_stack = 
+    g_array_set_size(process->execution_stack, depth - 1);
+  process->state = &g_array_index(process->execution_stack, LttvExecutionState,
+      depth - 2);
+  process->state->change = tfs->parent.timestamp;
+       
+       return 0;
+}
 
 static void pop_state(LttvTracefileState *tfs, LttvExecutionMode t)
 {
@@ -1192,6 +1215,7 @@ lttv_state_create_process(LttvTraceState *tcs, LttvProcessState *parent,
   es->entry = *timestamp;
   //g_assert(timestamp->tv_sec != 0);
   es->change = *timestamp;
+       es->cum_cpu_time = ltt_time_zero;
   es->s = LTTV_STATE_RUN;
 
   es = process->state = &g_array_index(process->execution_stack, 
@@ -1201,6 +1225,7 @@ lttv_state_create_process(LttvTraceState *tcs, LttvProcessState *parent,
   es->entry = *timestamp;
   //g_assert(timestamp->tv_sec != 0);
   es->change = *timestamp;
+       es->cum_cpu_time = ltt_time_zero;
   es->s = LTTV_STATE_WAIT_FORK;
        
        /* Allocate an empty function call stack. If it's empty, use 0x0. */

diff --git a/ltt/branches/poly/lttv/lttv/state.h b/ltt/branches/poly/lttv/lttv/state.h
index 35e17339cf8d011f85a2e5db53ab629c5b64a563..85ff18943c589b6abdf00ef901ac537835776d72 100644 (file)
--- a/ltt/branches/poly/lttv/lttv/state.h
+++ b/ltt/branches/poly/lttv/lttv/state.h
@@ -192,6 +192,7 @@ typedef struct _LttvExecutionState {
   LttvExecutionSubmode n;
   LttTime entry;
   LttTime change;
+       LttTime cum_cpu_time;
   LttvProcessStatus s;
 } LttvExecutionState;
 
@@ -299,6 +300,8 @@ void lttv_state_restore(LttvTraceState *self, LttvAttribute *container);
 void lttv_state_state_saved_free(LttvTraceState *self, 
     LttvAttribute *container);
 
+int lttv_state_pop_state_cleanup(LttvProcessState *process,
+               LttvTracefileState *tfs);
 
 #define LTTV_TRACEFILE_STATE_TYPE  (lttv_tracefile_state_get_type ())
 #define LTTV_TRACEFILE_STATE(obj)  (G_TYPE_CHECK_INSTANCE_CAST ((obj), LTTV_TRACEFILE_STATE_TYPE, LttvTracefileState))

diff --git a/ltt/branches/poly/lttv/lttv/stats.c b/ltt/branches/poly/lttv/lttv/stats.c
index 2dbf4a51a8d8bca236dd245375e8a58392c10192..875c1683d93c815985a90bb08320653a60925865 100644 (file)
--- a/ltt/branches/poly/lttv/lttv/stats.c
+++ b/ltt/branches/poly/lttv/lttv/stats.c
@@ -43,6 +43,7 @@ GQuark
        LTTV_STATS_FUNCTIONS,
   LTTV_STATS_EVENT_TYPES,
   LTTV_STATS_CPU_TIME,
+  LTTV_STATS_CUMULATIVE_CPU_TIME,
   LTTV_STATS_ELAPSED_TIME,
   LTTV_STATS_EVENTS,
   LTTV_STATS_EVENTS_COUNT,
@@ -405,9 +406,11 @@ find_event_tree(LttvTracefileStats *tfcs,
 {
   LttvAttribute *a, *prev_a;
        gchar fstring[MAX_64_HEX_STRING_LEN];
+       gint ret;
 
-       g_assert(snprintf(fstring, MAX_64_HEX_STRING_LEN-1,
-                               "0x%llX", function) > 0);
+       ret = snprintf(fstring, MAX_64_HEX_STRING_LEN-1,
+                               "0x%llX", function) > 0;
+       g_assert(ret > 0);
        fstring[MAX_64_HEX_STRING_LEN-1] = '\0';
 
   LttvTraceStats *tcs = (LttvTraceStats*)tfcs->parent.parent.t_context;
@@ -447,24 +450,29 @@ static void mode_change(LttvTracefileStats *tfcs)
   LttvTraceState *ts = (LttvTraceState *)tfcs->parent.parent.t_context;
   guint cpu = tfcs->parent.cpu;
   LttvProcessState *process = ts->running_process[cpu];
-  LttvAttributeValue cpu_time; 
+  LttvAttributeValue cpu_time, cum_cpu_time;
 
   LttTime delta;
 
-  lttv_attribute_find(tfcs->current_events_tree, LTTV_STATS_CPU_TIME, 
-      LTTV_TIME, &cpu_time);
   delta = ltt_time_sub(tfcs->parent.parent.timestamp, 
       process->state->change);
+
+  lttv_attribute_find(tfcs->current_events_tree, LTTV_STATS_CPU_TIME, 
+      LTTV_TIME, &cpu_time);
   *(cpu_time.v_time) = ltt_time_add(*(cpu_time.v_time), delta);
-}
 
+  process->state->cum_cpu_time = ltt_time_add(process->state->cum_cpu_time,
+                       delta);
+}
 
+/* Note : every mode_end must come with a cumulative cpu time update in the
+ * after hook */
 static void mode_end(LttvTracefileStats *tfcs)
 {
   LttvTraceState *ts = (LttvTraceState *)tfcs->parent.parent.t_context;
   guint cpu = tfcs->parent.cpu;
   LttvProcessState *process = ts->running_process[cpu];
-  LttvAttributeValue elapsed_time, cpu_time; 
+  LttvAttributeValue elapsed_time, cpu_time, cum_cpu_time; 
 
   LttTime delta;
 
@@ -479,9 +487,34 @@ static void mode_end(LttvTracefileStats *tfcs)
   delta = ltt_time_sub(tfcs->parent.parent.timestamp, 
       process->state->change);
   *(cpu_time.v_time) = ltt_time_add(*(cpu_time.v_time), delta);
+  process->state->cum_cpu_time = ltt_time_add(process->state->cum_cpu_time,
+                       delta);
+
+  lttv_attribute_find(tfcs->current_events_tree, LTTV_STATS_CUMULATIVE_CPU_TIME,
+      LTTV_TIME, &cum_cpu_time);
+  *(cum_cpu_time.v_time) = ltt_time_add(*(cum_cpu_time.v_time), 
+                       process->state->cum_cpu_time);
 }
 
 
+static void after_mode_end(LttvTracefileStats *tfcs)
+{
+  LttvTraceState *ts = (LttvTraceState *)tfcs->parent.parent.t_context;
+  guint cpu = tfcs->parent.cpu;
+  LttvProcessState *process = ts->running_process[cpu];
+  LttvAttributeValue cum_cpu_time;
+
+  LttTime nested_delta;
+
+  nested_delta = process->state->cum_cpu_time;
+  process->state->cum_cpu_time = ltt_time_zero;        /* For after traceset hook */
+
+  update_event_tree(tfcs);
+
+  process->state->cum_cpu_time = ltt_time_add(process->state->cum_cpu_time,
+                       nested_delta);
+}
+
 static gboolean before_syscall_entry(void *hook_data, void *call_data)
 {
   mode_change((LttvTracefileStats *)call_data);
@@ -505,7 +538,7 @@ gboolean before_syscall_exit(void *hook_data, void *call_data)
 
 static gboolean after_syscall_exit(void *hook_data, void *call_data)
 {
-  update_event_tree((LttvTracefileStats *)call_data);
+  after_mode_end((LttvTracefileStats *)call_data);
   return FALSE;
 }
 
@@ -533,7 +566,7 @@ gboolean before_trap_exit(void *hook_data, void *call_data)
 
 gboolean after_trap_exit(void *hook_data, void *call_data)
 {
-  update_event_tree((LttvTracefileStats *)call_data);
+  after_mode_end((LttvTracefileStats *)call_data);
   return FALSE;
 }
 
@@ -560,7 +593,7 @@ gboolean before_irq_exit(void *hook_data, void *call_data)
 
 gboolean after_irq_exit(void *hook_data, void *call_data)
 {
-  update_event_tree((LttvTracefileStats *)call_data);
+  after_mode_end((LttvTracefileStats *)call_data);
   return FALSE;
 }
 
@@ -587,13 +620,13 @@ gboolean before_soft_irq_exit(void *hook_data, void *call_data)
 
 gboolean after_soft_irq_exit(void *hook_data, void *call_data)
 {
-  update_event_tree((LttvTracefileStats *)call_data);
+  after_mode_end((LttvTracefileStats *)call_data);
   return FALSE;
 }
 
 gboolean before_function_entry(void *hook_data, void *call_data)
 {
-  mode_end((LttvTracefileStats *)call_data);
+  mode_change((LttvTracefileStats *)call_data);
   return FALSE;
 }
 
@@ -611,7 +644,7 @@ gboolean before_function_exit(void *hook_data, void *call_data)
 
 gboolean after_function_exit(void *hook_data, void *call_data)
 {
-  update_event_tree((LttvTracefileStats *)call_data);
+  after_mode_end((LttvTracefileStats *)call_data);
   return FALSE;
 }
 
@@ -630,8 +663,6 @@ gboolean before_schedchange(void *hook_data, void *call_data)
     
   gint state_out;
 
-  LttvProcessState *process;
-
   pid_out = ltt_event_get_unsigned(e, thf->f1);
   pid_in = ltt_event_get_unsigned(e, thf->f2);
   state_out = ltt_event_get_int(e, thf->f3);
@@ -640,12 +671,32 @@ gboolean before_schedchange(void *hook_data, void *call_data)
 
   mode_change(tfcs);
 
-  /* get the information for the process scheduled in */
+  return FALSE;
+}
 
-  process = lttv_state_find_process_or_create(ts, 
-      ANY_CPU, pid_in, &tfcs->parent.parent.timestamp);
+gboolean after_schedchange(void *hook_data, void *call_data)
+{
+  LttvTracefileStats *tfcs = (LttvTracefileStats *)call_data;
+
+  LttvTraceState *ts = (LttvTraceState*)tfcs->parent.parent.t_context;
 
+  LttEvent *e = ltt_tracefile_get_event(tfcs->parent.parent.tf);
+
+  LttvTraceHookByFacility *thf = (LttvTraceHookByFacility *)hook_data;
+
+  guint pid_in, pid_out;
+    
+  gint state_out;
+
+  LttvProcessState *process;
+
+  pid_out = ltt_event_get_unsigned(e, thf->f1);
+  pid_in = ltt_event_get_unsigned(e, thf->f2);
+  state_out = ltt_event_get_int(e, thf->f3);
+
+  /* get the information for the process scheduled in */
   guint cpu = tfcs->parent.cpu;
+  process = ts->running_process[cpu];
 
   find_event_tree(tfcs, process->pid_time,
       cpu,
@@ -654,11 +705,10 @@ gboolean before_schedchange(void *hook_data, void *call_data)
       &(tfcs->current_event_types_tree));
 
   /* compute the time waiting for the process to schedule in */
-
   mode_change(tfcs);
-  return FALSE;
-}
 
+       return FALSE;
+}
 
 gboolean process_fork(void *hook_data, void *call_data)
 {
@@ -699,6 +749,51 @@ gboolean every_event(void *hook_data, void *call_data)
   return FALSE;
 }
 
+static void lttv_stats_cleanup_process_state(gpointer key, gpointer value,
+               gpointer user_data)
+{
+       LttvTraceStats *tcs = (LttvTraceStats *)user_data;
+       LttvTraceState *ts = (LttvTraceState *)user_data;
+       LttvTracesetContext *tsc = ts->parent.ts_context;
+       LttvProcessState *process = (LttvProcessState *)value;
+       int i;
+       LttvTracefileStats **tfs = (LttvTracefileStats **)
+                       &g_array_index(ts->parent.tracefiles, LttvTracefileContext*,
+                                       process->cpu);
+       int cleanup_empty = 0;
+
+       do {
+               if(ltt_time_compare(process->state->cum_cpu_time, ltt_time_zero) != 0) {
+                       find_event_tree(*tfs, process->pid_time,
+                                       process->cpu,
+                                       process->current_function,
+                                       process->state->t, process->state->n, &((*tfs)->current_events_tree), 
+                                       &((*tfs)->current_event_types_tree));
+                       /* FIXME : ok, this is a hack. The time is infinite here :( */
+                       LttTime save_time = (*tfs)->parent.parent.timestamp;
+                       LttTime start, end;
+                       ltt_trace_time_span_get(ts->parent.t, &start, &end);
+                       (*tfs)->parent.parent.timestamp = end;
+                       mode_end(*tfs);
+                       (*tfs)->parent.parent.timestamp = save_time;
+               }
+               cleanup_empty = lttv_state_pop_state_cleanup(process,
+                               (LttvTracefileState *)*tfs);
+       } while(cleanup_empty != 1);
+}
+
+/* For each process in the state, for each of their stacked states,
+ * perform sum of needed values. */
+static void lttv_stats_cleanup_state(LttvTraceStats *tcs)
+{
+  LttvTraceState *ts = (LttvTraceState *)tcs;
+       
+#if 0
+       /* Does not work correctly FIXME. */
+       g_hash_table_foreach(ts->processes, lttv_stats_cleanup_process_state,
+                       tcs);
+#endif //0
+}
 
 void
 lttv_stats_sum_trace(LttvTraceStats *self, LttvAttribute *ts_stats)
@@ -728,6 +823,7 @@ lttv_stats_sum_trace(LttvTraceStats *self, LttvAttribute *ts_stats)
                        *function_mode_types_tree,
                        *trace_cpu_tree;
 
+
   main_tree = sum_container;
 
   lttv_attribute_find(sum_container,
@@ -736,6 +832,11 @@ lttv_stats_sum_trace(LttvTraceStats *self, LttvAttribute *ts_stats)
        trace_is_summed = *(value.v_uint);
   *(value.v_uint) = 1;
 
+       /* First cleanup the state : sum all stalled information (never ending
+        * states). */
+       if(!trace_is_summed)
+               lttv_stats_cleanup_state(self);
+       
   processes_tree = lttv_attribute_find_subdir(main_tree, 
                                               LTTV_STATS_PROCESSES);
   nb_process = lttv_attribute_get_number(processes_tree);
@@ -806,16 +907,16 @@ lttv_stats_sum_trace(LttvTraceStats *self, LttvAttribute *ts_stats)
                                                }
                                        }
                                        if(!trace_is_summed) {
-                                               lttv_attribute_recursive_add(function_tree, mode_types_tree);
+                                               //lttv_attribute_recursive_add(function_tree, mode_types_tree);
                                        }
                                }
                                if(!trace_is_summed) {
-                                       lttv_attribute_recursive_add(cpu_tree, function_tree);
-                                       lttv_attribute_recursive_add(process_tree, function_tree);
-                                       lttv_attribute_recursive_add(trace_cpu_tree, function_tree);
-                                       lttv_attribute_recursive_add(main_tree, function_tree);
+                                       //lttv_attribute_recursive_add(cpu_tree, function_tree);
+                                       //lttv_attribute_recursive_add(process_tree, function_tree);
+                                       //lttv_attribute_recursive_add(trace_cpu_tree, function_tree);
+                                       //lttv_attribute_recursive_add(main_tree, function_tree);
                                }
-                               lttv_attribute_recursive_add(ts_stats, function_tree);
+                               //lttv_attribute_recursive_add(ts_stats, function_tree);
                        }
     }
   }
@@ -980,8 +1081,8 @@ void lttv_stats_add_event_hooks(LttvTracesetStats *self)
 
     before_hooks = hooks;
 
-    hooks = g_array_sized_new(FALSE, FALSE, sizeof(LttvTraceHook), 13);
-    g_array_set_size(hooks, 13);
+    hooks = g_array_sized_new(FALSE, FALSE, sizeof(LttvTraceHook), 14);
+    g_array_set_size(hooks, 14);
                hn=0;
 
     ret = lttv_trace_find_hook(ts->parent.parent.t,
@@ -1040,6 +1141,13 @@ void lttv_stats_add_event_hooks(LttvTracesetStats *self)
         &g_array_index(hooks, LttvTraceHook, hn++));
     if(ret) hn--;
 
+    ret = lttv_trace_find_hook(ts->parent.parent.t,
+        LTT_FACILITY_PROCESS, LTT_EVENT_SCHEDCHANGE,
+        LTT_FIELD_OUT, LTT_FIELD_IN, LTT_FIELD_OUT_STATE,
+        after_schedchange, NULL, 
+        &g_array_index(hooks, LttvTraceHook, hn++));
+    if(ret) hn--;
+
     ret = lttv_trace_find_hook(ts->parent.parent.t,
         LTT_FACILITY_PROCESS, LTT_EVENT_FORK, 
         LTT_FIELD_PARENT_PID, LTT_FIELD_CHILD_PID, 0,
@@ -1210,7 +1318,8 @@ static void module_init()
   LTTV_STATS_FUNCTIONS = g_quark_from_string("functions");
   LTTV_STATS_EVENT_TYPES = g_quark_from_string("event_types");
   LTTV_STATS_CPU_TIME = g_quark_from_string("cpu time");
-  LTTV_STATS_ELAPSED_TIME = g_quark_from_string("elapsed time");
+  LTTV_STATS_CUMULATIVE_CPU_TIME = g_quark_from_string("cumulative cpu time (includes nested routines and modes)");
+  LTTV_STATS_ELAPSED_TIME = g_quark_from_string("elapsed time (includes per process waiting time)");
   LTTV_STATS_EVENTS = g_quark_from_string("events");
   LTTV_STATS_EVENTS_COUNT = g_quark_from_string("events count");
   LTTV_STATS_BEFORE_HOOKS = g_quark_from_string("saved stats before hooks");

diff --git a/ltt/branches/poly/lttv/lttv/stats.h b/ltt/branches/poly/lttv/lttv/stats.h
index e9939f2e61094fa28c09ded5f941499eabe555dc..b794b2b51634dd67139ecb673717c8125e1351a2 100644 (file)
--- a/ltt/branches/poly/lttv/lttv/stats.h
+++ b/ltt/branches/poly/lttv/lttv/stats.h
@@ -39,6 +39,7 @@
      "facility-event_type"
    events_count
    cpu_time
+        cumulative_cpu_time
    elapsed_time
    wait_time
    bytes_written
@@ -150,6 +151,7 @@ extern GQuark
   LTTV_STATS_FUNCTIONS,
   LTTV_STATS_EVENT_TYPES,
   LTTV_STATS_CPU_TIME,
+  LTTV_STATS_CUMULATIVE_CPU_TIME,
   LTTV_STATS_ELAPSED_TIME,
   LTTV_STATS_EVENTS,
   LTTV_STATS_EVENTS_COUNT,