[ltt-dev] LTTV Enhancement

Mathieu Desnoyers mathieu.desnoyers at polymtl.ca
Sat Nov 21 12:01:23 EST 2009


* Chris Smowton (cs448 at cam.ac.uk) wrote:
> Hey,
> 
> Here's a slightly more constructive patch: this one adds support in
> LTTV's generic state monitoring code and its control flow visualiser to
> note when a process is woken by another process using the
> sched_try_wakeup event.
> 
> Previously the woken process would continue to register its old state
> until such time as it got scheduled; here the process transitions to
> WAIT_CPU state (like preempted processes, indicating it is ready to run
> but not currently scheduled). Ordinarily we see this state exist very
> briefly, in between the device driver IRQ (typically) clearing it to run
> and the scheduler invocation after irq_exit, but on a heavily loaded
> system we might see a large stripe of dark yellow indicating the process
> is ready but cannot yet be allocated a core.
> 

This is indeed the right thing to do ! :) Thanks very much for the
patch.

I'll wait for feedback from Pierre-Marc, who maintains the resource
view, to see if this view too need to be updated. When I get his OK,
I'll pull your patch.

> The new code in controlflow/eventhooks.c is essentially a copy of the
> second half of before_schedchange -- it would be nice to factor these
> two and before_execmode, all of which basically identify a process,
> create state objects if necessary, and draw his line up to a certain
> time.

Indeed, but I never found time to do it ;) Also, performance is really
critical in these functions, so abstraction should ideally not involve
costly abstraction (e.g. added function calls to the hot path...).

Thanks !

Mathieu

> 
> Chris

> diff -r -uN lttv-original/lttv/lttv/state.c lttv-mine/lttv/lttv/state.c
> --- lttv-original/lttv/lttv/state.c	2009-11-12 22:43:00.000000000 +0000
> +++ lttv-mine/lttv/lttv/state.c	2009-11-19 19:33:05.000000000 +0000
> @@ -136,7 +136,9 @@
>      LTT_FIELD_ADDRESS,
>      LTT_FIELD_SYMBOL,
>      LTT_FIELD_IP,
> -    LTT_FIELD_FD;
> +    LTT_FIELD_FD,
> +    LTT_FIELD_STATE,
> +    LTT_FIELD_CPU_ID;
>  
>  LttvExecutionMode
>    LTTV_STATE_MODE_UNKNOWN,
> @@ -2933,6 +2935,32 @@
>    return FALSE;
>  }
>  
> +static gboolean sched_try_wakeup(void *hook_data, void *call_data) {
> +
> +  LttvTracefileState *s = (LttvTracefileState *)call_data;
> +  LttvProcessState *process;
> +  
> +  LttEvent *e = ltt_tracefile_get_event(s->parent.tf);
> +  LttvTraceHook *th = (LttvTraceHook *)hook_data;
> +  gint woken_pid;
> +  guint woken_cpu;
> +
> +  woken_pid = ltt_event_get_int(e, lttv_trace_get_hook_field(th, 0));
> +  woken_cpu = ltt_event_get_unsigned(e, lttv_trace_get_hook_field(th, 1));
> +
> +  process = lttv_state_find_process_or_create(
> +                  (LttvTraceState*)s->parent.t_context,
> +                  woken_cpu, woken_pid,
> +                  &s->parent.timestamp);
> +  process->state->s = LTTV_STATE_WAIT_CPU;
> +  process->state->change = s->parent.timestamp;
> +
> +  g_debug("Wakeup: process %d on CPU %u\n", woken_pid, woken_cpu);
> +
> +  return FALSE;
> +
> +}
> +
>  static gboolean schedchange(void *hook_data, void *call_data)
>  {
>    LttvTracefileState *s = (LttvTracefileState *)call_data;
> @@ -3639,6 +3667,12 @@
>          schedchange, NULL, &hooks);
>  
>      lttv_trace_find_hook(ts->parent.t,
> +	LTT_CHANNEL_KERNEL,
> +	LTT_EVENT_SCHED_TRY_WAKEUP,		 
> +	FIELD_ARRAY(LTT_FIELD_PID, LTT_FIELD_CPU_ID, LTT_FIELD_STATE),
> +	sched_try_wakeup, NULL, &hooks);
> +
> +    lttv_trace_find_hook(ts->parent.t,
>          LTT_CHANNEL_KERNEL,
>          LTT_EVENT_PROCESS_FORK,
>          FIELD_ARRAY(LTT_FIELD_PARENT_PID, LTT_FIELD_CHILD_PID,
> @@ -4484,6 +4518,8 @@
>    LTT_FIELD_SYMBOL        = g_quark_from_string("symbol");
>    LTT_FIELD_IP            = g_quark_from_string("ip");
>    LTT_FIELD_FD            = g_quark_from_string("fd");
> +  LTT_FIELD_STATE         = g_quark_from_string("state");
> +  LTT_FIELD_CPU_ID        = g_quark_from_string("cpu_id");
>    
>    LTTV_CPU_UNKNOWN = g_quark_from_string("unknown");
>    LTTV_CPU_IDLE = g_quark_from_string("idle");
> diff -r -uN lttv-original/lttv/lttv/state.h lttv-mine/lttv/lttv/state.h
> --- lttv-original/lttv/lttv/state.h	2009-10-17 22:46:13.000000000 +0100
> +++ lttv-mine/lttv/lttv/state.h	2009-11-19 18:47:14.000000000 +0000
> @@ -142,7 +142,9 @@
>      LTT_FIELD_ADDRESS,
>      LTT_FIELD_SYMBOL,
>      LTT_FIELD_IP,
> -    LTT_FIELD_FD;
> +    LTT_FIELD_FD,
> +    LTT_FIELD_STATE,
> +    LTT_FIELD_CPU_ID;
>  
>  typedef struct _LttvTracesetState LttvTracesetState;
>  typedef struct _LttvTracesetStateClass LttvTracesetStateClass;
> diff -r -uN lttv-original/lttv/modules/gui/controlflow/drawing.c lttv-mine/lttv/modules/gui/controlflow/drawing.c
> --- lttv-original/lttv/modules/gui/controlflow/drawing.c	2009-10-17 22:46:14.000000000 +0100
> +++ lttv-mine/lttv/modules/gui/controlflow/drawing.c	2009-11-20 15:48:03.000000000 +0000
> @@ -230,6 +230,14 @@
>            &hooks);
>  
>        lttv_trace_find_hook(ts->parent.t,
> +	  LTT_CHANNEL_KERNEL,
> +	  LTT_EVENT_SCHED_TRY_WAKEUP,		 
> +	  FIELD_ARRAY(LTT_FIELD_PID, LTT_FIELD_CPU_ID, LTT_FIELD_STATE),
> +	  before_trywakeup_hook,
> +	  events_request,
> +	  &hooks);
> +
> +      lttv_trace_find_hook(ts->parent.t,
>            LTT_CHANNEL_KERNEL,
>            LTT_EVENT_SYSCALL_EXIT,
>            NULL,
> diff -r -uN lttv-original/lttv/modules/gui/controlflow/eventhooks.c lttv-mine/lttv/modules/gui/controlflow/eventhooks.c
> --- lttv-original/lttv/modules/gui/controlflow/eventhooks.c	2009-10-17 22:46:14.000000000 +0100
> +++ lttv-mine/lttv/modules/gui/controlflow/eventhooks.c	2009-11-20 15:44:56.000000000 +0000
> @@ -277,6 +277,199 @@
>  
>  }
>  
> +/* Before try-wake-up hook. A process is being woken; we need to draw its line up to this point in time
> +   in that colour. This is basically like exec-state, but the change applies to a process other than that
> +   which is currently running. */
> +
> +int before_trywakeup_hook(void *hook_data, void *call_data)
> +{
> +  LttvTraceHook *th = (LttvTraceHook*)hook_data;
> +  EventsRequest *events_request = (EventsRequest*)th->hook_data;
> +  ControlFlowData *control_flow_data = events_request->viewer_data;
> +
> +  LttvTracefileContext *tfc = (LttvTracefileContext *)call_data;
> +
> +  LttvTracefileState *tfs = (LttvTracefileState *)call_data;
> +  LttvTraceState *ts = (LttvTraceState *)tfc->t_context;
> +
> +  LttEvent *e = ltt_tracefile_get_event(tfc->tf);
> +  gint target_pid_saved = tfc->target_pid;
> +
> +  LttTime evtime = ltt_event_time(e);
> +  LttvFilter *filter = control_flow_data->filter;
> +
> +  guint woken_pid;
> +  gint woken_cpu;
> +
> +  woken_pid = ltt_event_get_int(e, lttv_trace_get_hook_field(th, 0));
> +  woken_cpu = ltt_event_get_unsigned(e, lttv_trace_get_hook_field(th, 1));
> +  
> +  tfc->target_pid = woken_pid;
> +  if(!filter || !filter->head ||
> +    lttv_filter_tree_parse(filter->head,e,tfc->tf,
> +          tfc->t_context->t,tfc,NULL,NULL)) { 
> +
> +    /* First, check if the woken process is in the state computation
> +     * process list. If it is there, that means we must add it right now and
> +     * draw items from the beginning of the read for it. If it is not
> +     * present, it's a new process and it was not present : it will
> +     * be added after the state update. TOCHECK: What does that last para mean? */
> +    guint cpu = tfs->cpu;
> +    guint trace_num = ts->parent.index;
> +    LttvProcessState *process = lttv_state_find_process(ts, woken_cpu, woken_pid);
> +    
> +    if(process != NULL) {
> +      /* Well, the woken process existed : we must get it in the process hash
> +       * or add it, and draw its items.
> +       */
> +       /* Add process to process list (if not present) */
> +      guint pl_height = 0;
> +      HashedProcessData *hashed_process_data = NULL;
> +      ProcessList *process_list = control_flow_data->process_list;
> +      LttTime birth = process->creation_time;
> +      
> +      hashed_process_data = processlist_get_process_data(process_list,
> +              woken_pid,
> +              process->cpu,
> +              &birth,
> +              trace_num);
> +      if(hashed_process_data == NULL)
> +      {
> +        g_assert(woken_pid != process->ppid);
> +        /* Process not present */
> +        ProcessInfo *process_info;
> +        Drawing_t *drawing = control_flow_data->drawing;
> +        processlist_add(process_list,
> +            drawing,
> +            woken_pid,
> +            process->tgid,
> +            process->cpu,
> +            process->ppid,
> +            &birth,
> +            trace_num,
> +            process->name,
> +            process->brand,
> +            &pl_height,
> +            &process_info,
> +            &hashed_process_data);
> +        gtk_widget_set_size_request(drawing->drawing_area,
> +                                    -1,
> +                                    pl_height);
> +        gtk_widget_queue_draw(drawing->drawing_area);
> +
> +      }
> +  
> +      /* Now, the process is in the state hash and our own process hash.
> +       * We definitely can draw the items related to the ending state.
> +       */
> +      
> +      if(ltt_time_compare(hashed_process_data->next_good_time,
> +                          evtime) > 0)
> +      {
> +        if(hashed_process_data->x.middle_marked == FALSE) {
> +    
> +          TimeWindow time_window = 
> +            lttvwindow_get_time_window(control_flow_data->tab);
> +#ifdef EXTRA_CHECK
> +          if(ltt_time_compare(evtime, time_window.start_time) == -1
> +                || ltt_time_compare(evtime, time_window.end_time) == 1)
> +                    return FALSE;
> +#endif //EXTRA_CHECK
> +          Drawing_t *drawing = control_flow_data->drawing;
> +          guint width = drawing->width;
> +          guint x;
> +          convert_time_to_pixels(
> +                    time_window,
> +                    evtime,
> +                    width,
> +                    &x);
> +
> +          /* Draw collision indicator */
> +          gdk_gc_set_foreground(drawing->gc, &drawing_colors[COL_WHITE]);
> +          gdk_draw_point(hashed_process_data->pixmap,
> +                         drawing->gc,
> +                         x,
> +                         COLLISION_POSITION(hashed_process_data->height));
> +          hashed_process_data->x.middle_marked = TRUE;
> +        }
> +      } else {
> +        TimeWindow time_window = 
> +          lttvwindow_get_time_window(control_flow_data->tab);
> +#ifdef EXTRA_CHECK
> +        if(ltt_time_compare(evtime, time_window.start_time) == -1
> +              || ltt_time_compare(evtime, time_window.end_time) == 1)
> +                  return FALSE;
> +#endif //EXTRA_CHECK
> +        Drawing_t *drawing = control_flow_data->drawing;
> +        guint width = drawing->width;
> +        guint x;
> +        convert_time_to_pixels(
> +                  time_window,
> +                  evtime,
> +                  width,
> +                  &x);
> +
> +
> +        /* Jump over draw if we are at the same x position */
> +        if(x == hashed_process_data->x.middle &&
> +             hashed_process_data->x.middle_used)
> +        {
> +          if(hashed_process_data->x.middle_marked == FALSE) {
> +            /* Draw collision indicator */
> +            gdk_gc_set_foreground(drawing->gc, &drawing_colors[COL_WHITE]);
> +            gdk_draw_point(hashed_process_data->pixmap,
> +                           drawing->gc,
> +                           x,
> +                           COLLISION_POSITION(hashed_process_data->height));
> +            hashed_process_data->x.middle_marked = TRUE;
> +          }
> +          /* jump */
> +        } else {
> +          DrawContext draw_context;
> +
> +          /* Now create the drawing context that will be used to draw
> +           * items related to the last state. */
> +          draw_context.drawable = hashed_process_data->pixmap;
> +          draw_context.gc = drawing->gc;
> +          draw_context.pango_layout = drawing->pango_layout;
> +          draw_context.drawinfo.start.x = hashed_process_data->x.middle;
> +          draw_context.drawinfo.end.x = x;
> +
> +          draw_context.drawinfo.y.over = 1;
> +          draw_context.drawinfo.y.middle = (hashed_process_data->height/2);
> +          draw_context.drawinfo.y.under = hashed_process_data->height;
> +
> +          draw_context.drawinfo.start.offset.over = 0;
> +          draw_context.drawinfo.start.offset.middle = 0;
> +          draw_context.drawinfo.start.offset.under = 0;
> +          draw_context.drawinfo.end.offset.over = 0;
> +          draw_context.drawinfo.end.offset.middle = 0;
> +          draw_context.drawinfo.end.offset.under = 0;
> +
> +          {
> +            /* Draw the line */
> +            PropertiesLine prop_line = prepare_s_e_line(process);
> +            draw_line((void*)&prop_line, (void*)&draw_context);
> +
> +          }
> +          /* become the last x position */
> +          hashed_process_data->x.middle = x;
> +          hashed_process_data->x.middle_used = TRUE;
> +          hashed_process_data->x.middle_marked = FALSE;
> +
> +          /* Calculate the next good time */
> +          convert_pixels_to_time(width, x+1, time_window,
> +                                 &hashed_process_data->next_good_time);
> +        }
> +      }
> +    }
> +  }
> +
> +  tfc->target_pid = target_pid_saved;
> +
> +  return 0;
> +
> +}
>  
>  /* before_schedchange_hook
>   * 
> diff -r -uN lttv-original/lttv/modules/gui/controlflow/eventhooks.h lttv-mine/lttv/modules/gui/controlflow/eventhooks.h
> --- lttv-original/lttv/modules/gui/controlflow/eventhooks.h	2009-10-17 22:46:14.000000000 +0100
> +++ lttv-mine/lttv/modules/gui/controlflow/eventhooks.h	2009-11-20 15:48:31.000000000 +0000
> @@ -85,6 +85,7 @@
>   */
>  int before_schedchange_hook(void *hook_data, void *call_data);
>  int after_schedchange_hook(void *hook_data, void *call_data);
> +int before_trywakeup_hook(void *hook_data, void *call_data);
>  int before_execmode_hook(void *hook_data, void *call_data);
>  int after_execmode_hook(void *hook_data, void *call_data);
>  


-- 
Mathieu Desnoyers
OpenPGP key fingerprint: 8CD5 52C3 8E3C 4140 715F  BA06 3F25 A8FE 3BAE 9A68




More information about the lttng-dev mailing list