Seeing what is happening: Task activation, execution times and CPU usage.

The way in which the mesures are token is the following: Every time the scheduler makes a context switch, the time at the new process enters is annotated and the time at the old process exits from the CPU is recorded. Next, a message is sended thorough a rtlinux FIFO, indicating the thread id, the time at it reaches the CPU and the time at the thread left it. In a similar way the resume time of tasks is reported. At the other side, in user space, a user process is listening from that fifo, reading the scheduler messages. Finally a graphicall tool interprets the messages and builts a chronogram. In a similar way, the tasks CPU usage during an interval of time is reported to the system. Bellow the scheduler code added is showed:

$$\mbox{ \epsfxsize =70mm \epsffile{images/measures.eps}}$$

$\parbox{7cm}{{\bf FIGURE \arabic{figcounter}:}\quad {\it Taking measures of the tasks activation and resume times. } }$

 
int rtl_schedule (void)
{
                      ..........

        for (t = sched->rtl_tasks; t; t = t->next) {
                /* expire timers */
                if (test_bit(RTL_THREAD_TIMERARMED, &t->threadflags)) {
                        if (now >= t->resume_time) {
                                clear_bit(RTL_THREAD_TIMERARMED, &t->threadflags);
                                rtl_sigaddset (&t->pending, RTL_SIGNAL_TIMER);
                                if (t->period != 0) { /* periodic */
                                        t->resume_time += t->period;
#ifdef __CPU_TRACER
                                        if (t != &sched->rtl_linux_task)
                                            rt_print_request(events,t,0,FIFO);
                                        else
                                            rt_print_request(events,t,7,FIFO);
#endif
                      ...........
                                }

                        }
                }
                
                /* and find highest priority runnable task */
                if ((t->pending & ~t->blocked) && (!new_task ||
                        (t->sched_param.sched_priority > new_task->sched_param.sched_priority))) {
                                new_task = t;
                }
        }

                      ............

        if (new_task != sched->rtl_current) { /* switch out old, switch in new */
                if (new_task ==  &sched->rtl_linux_task) {
                        rtl_make_rt_system_idle();

                } else {
                        rtl_make_rt_system_active(); 
                }

                rtl_trace2 (RTL_TRACE_SCHED_CTX_SWITCH, (long) new_task);

#ifdef __CPU_TRACER
        write_activ(sched,events,ini_time,now,FIFO);
#endif
#ifdef __CPU_USAGE
        t_u_counter[(int)sched->rtl_current->user[0]]+=now-ini_time;
#endif
#ifdef __CPU_USAGE
                {
                  int i=0;
                  hrtime_t time_diff=now-last_sample;
                  if (time_diff>=PERIOD){
                    for (i=0; i<ntasks; i++) 
                      {
                        t_usage[i]=(((t_u_counter[i]-last_t_u_counter[i])*UNIT)/time_diff); 
                        last_t_u_counter[i]=t_u_counter[i];
                      }// end for.
                    last_sample=now;
                    usage_window[sample%window_size]=t_usage[0];
                    sample++;
                  }
                }// end embedded code.
#endif
        
#ifdef __CPU_TRACER
                ini_time=now;
#endif
                rtl_switch_to(&sched->rtl_current, new_task);
                 ..........
}