On 17 November 2016 at 17:34, Juri Lelli juri.lelli@arm.com wrote:

Fix various compilation warnings in one go.

Signed-off-by: Juri Lelli juri.lelli@arm.com

Acked-by: Vincent Guittot vincent.guittot@linaro.org

---

libdl/dl_syscalls.h | 4 +++- src/rt-app.c | 4 ++-- src/rt-app_args.h | 3 --- src/rt-app_parse_config.h | 2 ++ src/rt-app_utils.c | 13 +++++++++++-- src/rt-app_utils.h | 3 +++ 6 files changed, 21 insertions(+), 8 deletions(-)

diff --git a/libdl/dl_syscalls.h b/libdl/dl_syscalls.h index 27cbfe16882d..ca07503ea744 100644 --- a/libdl/dl_syscalls.h +++ b/libdl/dl_syscalls.h @@ -17,7 +17,9 @@ #define __DL_SYSCALLS__

#include <linux/kernel.h> -#include <linux/unistd.h> +#define _GNU_SOURCE +#include <unistd.h> +#include <sys/syscall.h> #include <time.h> #include <linux/types.h>

diff --git a/src/rt-app.c b/src/rt-app.c index 5283ac7fd668..211dd77da98f 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -170,7 +170,7 @@ int calibrate_cpu_cycles(int clock)

}

-static inline loadwait(unsigned long exec) +static inline unsigned long loadwait(unsigned long exec) { unsigned long load_count;

@@ -358,7 +358,7 @@ int run(int ind, phase_data_t *pdata, unsigned long *duration, for (i = 0; i < nbevents; i++) { if (!continue_running && !lock)

•                   return;
  

•                   return perf;
  
            log_debug("[%d] runs events %d type %d ", ind, i, events[i].type);
            if (opts.ftrace)
  

diff --git a/src/rt-app_args.h b/src/rt-app_args.h index 9bbde384328b..23ba50c5f343 100644 --- a/src/rt-app_args.h +++ b/src/rt-app_args.h @@ -36,10 +36,7 @@ Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA. #ifdef DLSCHED #include "dl_syscalls.h" #endif

-#ifdef JSON #include "rt-app_parse_config.h" -#endif

#define DEFAULT_THREAD_PRIORITY 10 #define PATH_LENGTH 256 diff --git a/src/rt-app_parse_config.h b/src/rt-app_parse_config.h index 023cabd2ca62..9b0e5faf425d 100644 --- a/src/rt-app_parse_config.h +++ b/src/rt-app_parse_config.h @@ -45,5 +45,7 @@ Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.

void parse_config(const char *filename, rtapp_options_t *opts); +void +parse_config_stdin(rtapp_options_t *opts);

#endif // _RTAPP_PARSE_CONFIG_H diff --git a/src/rt-app_utils.c b/src/rt-app_utils.c index c4840db89625..887bfc8ef79e 100644 --- a/src/rt-app_utils.c +++ b/src/rt-app_utils.c @@ -19,6 +19,8 @@ along with this program; if not, write to the Free Software Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA. */

+#include <errno.h> +#include <string.h> #include "rt-app_utils.h"

unsigned long @@ -253,7 +255,7 @@ resource_to_string(resource_t resource, char *resource_name) void ftrace_write(int mark_fd, const char *fmt, ...) { va_list ap;

•   int n, size = BUF_SIZE;
  

•   int n, size = BUF_SIZE, ret;
    char *tmp, *ntmp;
  
    if (mark_fd < 0) {
  

@@ -274,8 +276,15 @@ void ftrace_write(int mark_fd, const char *fmt, ...)

            /* If it worked return success */
            if (n > -1 && n < size) {

•                   write(mark_fd, tmp, n);
  

•                   ret = write(mark_fd, tmp, n);
                    free(tmp);
  

•                   if (ret < 0) {
  

•                           log_error("Cannot write mark_fd: %s\n",
  

•                                           strerror(errno));
  

•                           exit(EXIT_FAILURE);
  

•                   } else if (ret < n) {
  

•                           log_debug("Cannot write all bytes at once into mark_fd\n");
  

•                   }
                    return;
            }
  
  

diff --git a/src/rt-app_utils.h b/src/rt-app_utils.h index 64f97f60aaab..a41d8ad205aa 100644 --- a/src/rt-app_utils.h +++ b/src/rt-app_utils.h @@ -28,6 +28,9 @@ Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA. #include <string.h> #include <stdarg.h> #include <stdlib.h> +#define _GNU_SOURCE +#include <unistd.h> +#include <sys/syscall.h> #include "rt-app_types.h"

#ifndef LOG_PREFIX

2.10.0

On 17 November 2016 at 17:34, Juri Lelli juri.lelli@arm.com wrote:

Also a barrier is added so that execution starts at the same instant for everybody.

Signed-off-by: Juri Lelli juri.lelli@arm.com

Acked-by: Vincent Guittot vincent.guittot@linaro.org

---

src/rt-app.c | 33 ++++++++++++++++++++++++++------- 1 file changed, 26 insertions(+), 7 deletions(-)

diff --git a/src/rt-app.c b/src/rt-app.c index 211dd77da98f..442771f553f9 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -35,6 +35,8 @@ static int nthreads; static volatile sig_atomic_t running_threads; static int p_load; rtapp_options_t opts; +static struct timespec t_zero; +static pthread_barrier_t threads_barrier;

static ftrace_data_t ft_data = { .debugfs = "/sys/kernel/debug", @@ -217,7 +219,8 @@ static void memload(unsigned long count, struct _rtapp_iomem_buf *iomem) }

static int run_event(event_data_t *event, int dry_run,

•           unsigned long *perf, unsigned long *duration, rtapp_resource_t *resources)
  

•           unsigned long *perf, unsigned long *duration, rtapp_resource_t *resources,
  

•           struct timespec *t_first)
  

{ rtapp_resource_t *rdata = &(resources[event->res]); rtapp_resource_t *ddata = &(resources[event->dep]); @@ -303,7 +306,7 @@ static int run_event(event_data_t *event, int dry_run,

                    if (rdata->res.timer.init == 0) {
                            rdata->res.timer.init = 1;

•                           clock_gettime(CLOCK_MONOTONIC, &rdata->res.timer.t_next);
  

•                           rdata->res.timer.t_next = *t_first;
                    }
  
                    rdata->res.timer.t_next = timespec_add(&rdata->res.timer.t_next, &t_period);
  

@@ -348,7 +351,8 @@ static int run_event(event_data_t *event, int dry_run, }

int run(int ind, phase_data_t *pdata, unsigned long *duration,

•           rtapp_resource_t *resources)
  

•           rtapp_resource_t *resources,
  

•           struct timespec *t_first)
  

{ event_data_t *events = pdata->events; int nbevents = pdata->nbevents; @@ -365,7 +369,7 @@ int run(int ind, phase_data_t *pdata, unsigned long *duration, log_ftrace(ft_data.marker_fd, "[%d] executing %d", ind, i);

•           lock += run_event(&events[i], !continue_running, &perf, duration, resources);
  

•           lock += run_event(&events[i], !continue_running, &perf, duration, resources, t_first);
    }
  
    return perf;
  

@@ -411,7 +415,7 @@ void *thread_body(void *arg) thread_data_t *data = (thread_data_t*) arg; phase_data_t *pdata; struct sched_param param;

•   struct timespec t_start, t_end;
  

•   struct timespec t_start, t_end, t_first;
    unsigned long t_start_usec;
    unsigned long perf, duration;
    timing_point_t *curr_timing;
  

@@ -536,6 +540,21 @@ void *thread_body(void *arg) } }

•   if (data->ind == 0) {
  

•           /*
  

•            * Only first thread sets t_zero. Other threads sync with this
  

•            * timestamp.
  

•            */
  

•           clock_gettime(CLOCK_MONOTONIC, &t_zero);
  

•           if (opts.ftrace)
  

•                   log_ftrace(ft_data.marker_fd,
  

•                           "[%d] sets zero time",
  

•                           data->ind);
  

•   }
  

•   pthread_barrier_wait(&threads_barrier);
  

•   t_first = t_zero;
  

•   log_notice("[%d] starting thread ...\n", data->ind);
  
    fprintf(data->log_handler, "#idx\tperf\trun\tperiod\tstart\t\tend\t\trel_st\n");
  

@@ -571,7 +590,7 @@ void *thread_body(void *arg)

            duration = 0;
            clock_gettime(CLOCK_MONOTONIC, &t_start);

•           perf = run(data->ind, pdata, &duration, *(data->resources));
  

•           perf = run(data->ind, pdata, &duration, *(data->resources), &t_first);
            clock_gettime(CLOCK_MONOTONIC, &t_end);
  
            if (timings)
  

@@ -660,7 +679,7 @@ int main(int argc, char* argv[]) /* allocated threads */ nthreads = opts.nthreads; threads = malloc(nthreads * sizeof(pthread_t));

•   running_threads = 0;
  

•   pthread_barrier_init(&threads_barrier, NULL, nthreads);
  
    /* install a signal handler for proper shutdown */
    signal(SIGQUIT, shutdown);
  

-- 2.10.0

On 17 November 2016 at 17:34, Juri Lelli juri.lelli@arm.com wrote:

Add wake-up latency metric (a la cyclictest).

Signed-off-by: Juri Lelli juri.lelli@arm.com

src/rt-app.c | 29 +++++++++++++++++++---------- src/rt-app_types.h | 1 + src/rt-app_utils.c | 5 +++-- 3 files changed, 23 insertions(+), 12 deletions(-)

diff --git a/src/rt-app.c b/src/rt-app.c index 442771f553f9..d23c3074f057 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -220,7 +220,7 @@ static void memload(unsigned long count, struct _rtapp_iomem_buf *iomem)

static int run_event(event_data_t *event, int dry_run, unsigned long *perf, unsigned long *duration, rtapp_resource_t *resources,

•           struct timespec *t_first)
  

•           struct timespec *t_first, unsigned long *wu_latency)
  

{ rtapp_resource_t *rdata = &(resources[event->res]); rtapp_resource_t *ddata = &(resources[event->dep]); @@ -299,7 +299,7 @@ static int run_event(event_data_t *event, int dry_run, break; case rtapp_timer: {

•                   struct timespec t_period, t_now;
  

•                   struct timespec t_period, t_now, t_wu;
                    log_debug("timer %d ", event->duration);
  
                    t_period = usec_to_timespec(event->duration);
  

@@ -311,10 +311,15 @@ static int run_event(event_data_t *event, int dry_run,

                    rdata->res.timer.t_next = timespec_add(&rdata->res.timer.t_next, &t_period);
                    clock_gettime(CLOCK_MONOTONIC, &t_now);

•                   if (timespec_lower(&t_now, &rdata->res.timer.t_next))
  

•                   if (timespec_lower(&t_now, &rdata->res.timer.t_next)) {
                            clock_nanosleep(CLOCK_MONOTONIC, TIMER_ABSTIME, &rdata->res.timer.t_next, NULL);
  

•                   else
  

•                           clock_gettime(CLOCK_MONOTONIC, &t_now);
  

•                           t_wu = timespec_sub(&t_now, &rdata->res.timer.t_next);
  

•                           *wu_latency = timespec_to_usec(&t_wu);
  

•                   } else {
                            clock_gettime(CLOCK_MONOTONIC, &rdata->res.timer.t_next);
  

•                           *wu_latency = 0UL;
  

•                   }
            }
            break;
    case rtapp_suspend:
  

@@ -352,7 +357,8 @@ static int run_event(event_data_t *event, int dry_run,

int run(int ind, phase_data_t *pdata, unsigned long *duration, rtapp_resource_t *resources,

•           struct timespec *t_first)
  

•           struct timespec *t_first,
  

•           unsigned long *wu_latency)
  

{ event_data_t *events = pdata->events; int nbevents = pdata->nbevents; @@ -369,7 +375,7 @@ int run(int ind, phase_data_t *pdata, unsigned long *duration, log_ftrace(ft_data.marker_fd, "[%d] executing %d", ind, i);

•           lock += run_event(&events[i], !continue_running, &perf, duration, resources, t_first);
  

•           lock += run_event(&events[i], !continue_running, &perf, duration, resources, t_first, wu_latency);
    }
  
    return perf;
  

@@ -417,7 +423,7 @@ void *thread_body(void *arg) struct sched_param param; struct timespec t_start, t_end, t_first; unsigned long t_start_usec;

•   unsigned long perf, duration;
  

•   unsigned long perf, duration, wu_latency;
    timing_point_t *curr_timing;
    timing_point_t *timings;
    timing_point_t tmp_timing;
  

@@ -557,7 +563,9 @@ void *thread_body(void *arg)

    log_notice("[%d] starting thread ...\n", data->ind);

•   fprintf(data->log_handler, "#idx\tperf\trun\tperiod\tstart\t\tend\t\trel_st\n");
  

•   fprintf(data->log_handler, "%s %8s %8s %8s %15s %15s %15s %10s\n",
  

replacing tab with space breaks the cpufreq_governor_efficiency script

•                              "#idx", "perf", "run", "period",
  

•                              "start", "end", "rel_st", "wu_lat");
  
    if (opts.ftrace)
            log_ftrace(ft_data.marker_fd, "[%d] starts", data->ind);
  

@@ -588,9 +596,9 @@ void *thread_body(void *arg) log_ftrace(ft_data.marker_fd, "[%d] begins loop %d phase %d step %d", data->ind, i, j, loop); log_debug("[%d] begins loop %d phase %d step %d", data->ind, i, j, loop);;

•           duration = 0;
  

•           duration = wu_latency = 0;
            clock_gettime(CLOCK_MONOTONIC, &t_start);
  

•           perf = run(data->ind, pdata, &duration, *(data->resources), &t_first);
  

•           perf = run(data->ind, pdata, &duration, *(data->resources), &t_first, &wu_latency);
            clock_gettime(CLOCK_MONOTONIC, &t_end);
  
            if (timings)
  

@@ -608,6 +616,7 @@ void *thread_body(void *arg) curr_timing->period = timespec_to_usec(&t_diff); curr_timing->duration = duration; curr_timing->perf = perf;

•           curr_timing->wu_latency = wu_latency;
  
            if (opts.logsize && !timings)
                    log_timing(data->log_handler, curr_timing);
  

diff --git a/src/rt-app_types.h b/src/rt-app_types.h index 57fb80d363d5..4c20f43cb627 100644 --- a/src/rt-app_types.h +++ b/src/rt-app_types.h @@ -191,6 +191,7 @@ typedef struct _timing_point_t { unsigned long perf; unsigned long duration; unsigned long period;

•   unsigned long wu_latency;
    __u64 start_time;
    __u64 end_time;
    __u64 rel_start_time;
  

diff --git a/src/rt-app_utils.c b/src/rt-app_utils.c index 887bfc8ef79e..28896c9a76e6 100644 --- a/src/rt-app_utils.c +++ b/src/rt-app_utils.c @@ -134,14 +134,15 @@ void log_timing(FILE *handler, timing_point_t *t) { fprintf(handler,

•           "%d\t%lu\t%lu\t%lu\t%llu\t%llu\t%llu",
  

•           "%4d %8lu %8lu %8lu %15llu %15llu %15llu %10lu",
            t->ind,
            t->perf,
            t->duration,
            t->period,
            t->start_time,
            t->end_time,
  

•           t->rel_start_time
  

•           t->rel_start_time,
  

•           t->wu_latency
    );
    fprintf(handler, "\n");
  

}

2.10.0

On 18 November 2016 at 17:26, Juri Lelli juri.lelli@arm.com wrote:

On 18/11/16 16:34, Vincent Guittot wrote:

...

On 17 November 2016 at 17:34, Juri Lelli juri.lelli@arm.com wrote:

[...]

...

...

@@ -557,7 +563,9 @@ void *thread_body(void *arg)

    log_notice("[%d] starting thread ...\n", data->ind);

•   fprintf(data->log_handler, "#idx\tperf\trun\tperiod\tstart\t\tend\t\trel_st\n");
  

•   fprintf(data->log_handler, "%s %8s %8s %8s %15s %15s %15s %10s\n",
  

replacing tab with space breaks the cpufreq_governor_efficiency script

I'm not very familiar with the script, but does this fix it?

---

doc/examples/cpufreq_governor_efficiency/dvfs.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/doc/examples/cpufreq_governor_efficiency/dvfs.sh b/doc/examples/cpufreq_governor_efficiency/dvfs.sh index 7caee7d437f7..ac69a53086e2 100755 --- a/doc/examples/cpufreq_governor_efficiency/dvfs.sh +++ b/doc/examples/cpufreq_governor_efficiency/dvfs.sh @@ -32,7 +32,7 @@ if [ $1 ] ; then sum=0 loop=0 overrun=0

•   for i in $(cat rt-app_$1_run$3us_sleep$4us.log | sed '1d;n;d' | sed '1d' |cut -f 3); do
  

•   for i in $(cat rt-app_$1_run$3us_sleep$4us.log | sed '1d;n;d' | sed '1d' | awk '{print $3}'); do
  

yes, it is

            loop=$(expr $loop + 1)
            sum=$(expr $sum + $i)
            if [ $4 -le $i ] ; then

On 18-Nov 16:47, Juri Lelli wrote:

On 18/11/16 17:33, Vincent Guittot wrote:

...

On 18 November 2016 at 17:26, Juri Lelli juri.lelli@arm.com wrote:

...

On 18/11/16 16:34, Vincent Guittot wrote:

...

On 17 November 2016 at 17:34, Juri Lelli juri.lelli@arm.com wrote:

[...]

...

...

@@ -557,7 +563,9 @@ void *thread_body(void *arg)

    log_notice("[%d] starting thread ...\n", data->ind);

•   fprintf(data->log_handler, "#idx\tperf\trun\tperiod\tstart\t\tend\t\trel_st\n");
  

•   fprintf(data->log_handler, "%s %8s %8s %8s %15s %15s %15s %10s\n",
  

replacing tab with space breaks the cpufreq_governor_efficiency script

I'm not very familiar with the script, but does this fix it?

---

doc/examples/cpufreq_governor_efficiency/dvfs.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/doc/examples/cpufreq_governor_efficiency/dvfs.sh b/doc/examples/cpufreq_governor_efficiency/dvfs.sh index 7caee7d437f7..ac69a53086e2 100755 --- a/doc/examples/cpufreq_governor_efficiency/dvfs.sh +++ b/doc/examples/cpufreq_governor_efficiency/dvfs.sh @@ -32,7 +32,7 @@ if [ $1 ] ; then sum=0 loop=0 overrun=0

•   for i in $(cat rt-app_$1_run$3us_sleep$4us.log | sed '1d;n;d' | sed '1d' |cut -f 3); do
  

•   for i in $(cat rt-app_$1_run$3us_sleep$4us.log | sed '1d;n;d' | sed '1d' | awk '{print $3}'); do
  

This can be further simplified using a single awk command to: a) skip all header line (assuming they start by #) b) printing the third column of all the following pair numbered lines

which is something like:

LOGFILE=rt-app_$1_run$3us_sleep$4us.log for i in $(awk '/^#/{HC++; next;} {SN=NR-HC+1; if(SN%2){print $3}}' $LOGFILE)

where I've used: HC (HeaderCount) : counter of header line SN (SampleNumber) : counter of samples lines NR (Line Number) : awk's predefined line number variable

On 21 November 2016 at 10:28, Vincent Guittot vincent.guittot@linaro.org wrote:

On 17 November 2016 at 17:34, Juri Lelli juri.lelli@arm.com wrote:

...

Add wake-up latency metric (a la cyclictest).

Signed-off-by: Juri Lelli juri.lelli@arm.com

src/rt-app.c | 29 +++++++++++++++++++---------- src/rt-app_types.h | 1 + src/rt-app_utils.c | 5 +++-- 3 files changed, 23 insertions(+), 12 deletions(-)

diff --git a/src/rt-app.c b/src/rt-app.c index 442771f553f9..d23c3074f057 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -220,7 +220,7 @@ static void memload(unsigned long count, struct _rtapp_iomem_buf *iomem)

static int run_event(event_data_t *event, int dry_run, unsigned long *perf, unsigned long *duration, rtapp_resource_t *resources,

•           struct timespec *t_first)
  

•           struct timespec *t_first, unsigned long *wu_latency)
  

{ rtapp_resource_t *rdata = &(resources[event->res]); rtapp_resource_t *ddata = &(resources[event->dep]); @@ -299,7 +299,7 @@ static int run_event(event_data_t *event, int dry_run, break; case rtapp_timer: {

•                   struct timespec t_period, t_now;
  

•                   struct timespec t_period, t_now, t_wu;
                    log_debug("timer %d ", event->duration);
  
                    t_period = usec_to_timespec(event->duration);
  

@@ -311,10 +311,15 @@ static int run_event(event_data_t *event, int dry_run,

                    rdata->res.timer.t_next = timespec_add(&rdata->res.timer.t_next, &t_period);
                    clock_gettime(CLOCK_MONOTONIC, &t_now);

•                   if (timespec_lower(&t_now, &rdata->res.timer.t_next))
  

•                   if (timespec_lower(&t_now, &rdata->res.timer.t_next)) {
                            clock_nanosleep(CLOCK_MONOTONIC, TIMER_ABSTIME, &rdata->res.timer.t_next, NULL);
  

•                   else
  

•                           clock_gettime(CLOCK_MONOTONIC, &t_now);
  

•                           t_wu = timespec_sub(&t_now, &rdata->res.timer.t_next);
  

•                           *wu_latency = timespec_to_usec(&t_wu);
  

You should add the same wake up latency metric for the sleep event

...

•                   } else {
                            clock_gettime(CLOCK_MONOTONIC, &rdata->res.timer.t_next);
  

•                           *wu_latency = 0UL;
  

•                   }
            }
            break;
    case rtapp_suspend:
  

@@ -352,7 +357,8 @@ static int run_event(event_data_t *event, int dry_run,

int run(int ind, phase_data_t *pdata, unsigned long *duration, rtapp_resource_t *resources,

•           struct timespec *t_first)
  

•           struct timespec *t_first,
  

•           unsigned long *wu_latency)
  

{ event_data_t *events = pdata->events; int nbevents = pdata->nbevents; @@ -369,7 +375,7 @@ int run(int ind, phase_data_t *pdata, unsigned long *duration, log_ftrace(ft_data.marker_fd, "[%d] executing %d", ind, i);

•           lock += run_event(&events[i], !continue_running, &perf, duration, resources, t_first);
  

•           lock += run_event(&events[i], !continue_running, &perf, duration, resources, t_first, wu_latency);
    }
  
    return perf;
  

@@ -417,7 +423,7 @@ void *thread_body(void *arg) struct sched_param param; struct timespec t_start, t_end, t_first; unsigned long t_start_usec;

•   unsigned long perf, duration;
  

•   unsigned long perf, duration, wu_latency;
    timing_point_t *curr_timing;
    timing_point_t *timings;
    timing_point_t tmp_timing;
  

@@ -557,7 +563,9 @@ void *thread_body(void *arg)

    log_notice("[%d] starting thread ...\n", data->ind);

•   fprintf(data->log_handler, "#idx\tperf\trun\tperiod\tstart\t\tend\t\trel_st\n");
  

•   fprintf(data->log_handler, "%s %8s %8s %8s %15s %15s %15s %10s\n",
  

•                              "#idx", "perf", "run", "period",
  

•                              "start", "end", "rel_st", "wu_lat");
  
    if (opts.ftrace)
            log_ftrace(ft_data.marker_fd, "[%d] starts", data->ind);
  

@@ -588,9 +596,9 @@ void *thread_body(void *arg) log_ftrace(ft_data.marker_fd, "[%d] begins loop %d phase %d step %d", data->ind, i, j, loop); log_debug("[%d] begins loop %d phase %d step %d", data->ind, i, j, loop);;

•           duration = 0;
  

•           duration = wu_latency = 0;
            clock_gettime(CLOCK_MONOTONIC, &t_start);
  

•           perf = run(data->ind, pdata, &duration, *(data->resources), &t_first);
  

•           perf = run(data->ind, pdata, &duration, *(data->resources), &t_first, &wu_latency);
            clock_gettime(CLOCK_MONOTONIC, &t_end);
  
            if (timings)
  

@@ -608,6 +616,7 @@ void *thread_body(void *arg) curr_timing->period = timespec_to_usec(&t_diff); curr_timing->duration = duration; curr_timing->perf = perf;

•           curr_timing->wu_latency = wu_latency;
  

What happen if we have several timer in one phase ? we will only get the last wake up latency, isn't it ?

...

            if (opts.logsize && !timings)
                    log_timing(data->log_handler, curr_timing);

diff --git a/src/rt-app_types.h b/src/rt-app_types.h index 57fb80d363d5..4c20f43cb627 100644 --- a/src/rt-app_types.h +++ b/src/rt-app_types.h @@ -191,6 +191,7 @@ typedef struct _timing_point_t { unsigned long perf; unsigned long duration; unsigned long period;

•   unsigned long wu_latency;
    __u64 start_time;
    __u64 end_time;
    __u64 rel_start_time;
  

diff --git a/src/rt-app_utils.c b/src/rt-app_utils.c index 887bfc8ef79e..28896c9a76e6 100644 --- a/src/rt-app_utils.c +++ b/src/rt-app_utils.c @@ -134,14 +134,15 @@ void log_timing(FILE *handler, timing_point_t *t) { fprintf(handler,

•           "%d\t%lu\t%lu\t%lu\t%llu\t%llu\t%llu",
  

•           "%4d %8lu %8lu %8lu %15llu %15llu %15llu %10lu",
            t->ind,
            t->perf,
            t->duration,
            t->period,
            t->start_time,
            t->end_time,
  

•           t->rel_start_time
  

•           t->rel_start_time,
  

•           t->wu_latency
    );
    fprintf(handler, "\n");
  

}

2.10.0

Le Monday 21 Nov 2016 à 12:26:03 (+0000), Juri Lelli a écrit :

On 21/11/16 10:33, Vincent Guittot wrote:

...

On 21 November 2016 at 10:28, Vincent Guittot vincent.guittot@linaro.org wrote:

...

On 17 November 2016 at 17:34, Juri Lelli juri.lelli@arm.com wrote:

[...]

...

...

...

    case rtapp_timer:
            {

•                   struct timespec t_period, t_now;
  

•                   struct timespec t_period, t_now, t_wu;
                    log_debug("timer %d ", event->duration);
  
                    t_period = usec_to_timespec(event->duration);
  

@@ -311,10 +311,15 @@ static int run_event(event_data_t *event, int dry_run,

                    rdata->res.timer.t_next = timespec_add(&rdata->res.timer.t_next, &t_period);
                    clock_gettime(CLOCK_MONOTONIC, &t_now);

•                   if (timespec_lower(&t_now, &rdata->res.timer.t_next))
  

•                   if (timespec_lower(&t_now, &rdata->res.timer.t_next)) {
                            clock_nanosleep(CLOCK_MONOTONIC, TIMER_ABSTIME, &rdata->res.timer.t_next, NULL);
  

•                   else
  

•                           clock_gettime(CLOCK_MONOTONIC, &t_now);
  

•                           t_wu = timespec_sub(&t_now, &rdata->res.timer.t_next);
  

•                           *wu_latency = timespec_to_usec(&t_wu);
  

You should add the same wake up latency metric for the sleep event

OK, will look into it.

...

...

...

•                   } else {
                            clock_gettime(CLOCK_MONOTONIC, &rdata->res.timer.t_next);
  

•                           *wu_latency = 0UL;
  

•                   }
            }
            break;
  

[...]

...

...

...

@@ -608,6 +616,7 @@ void *thread_body(void *arg) curr_timing->period = timespec_to_usec(&t_diff); curr_timing->duration = duration; curr_timing->perf = perf;

•           curr_timing->wu_latency = wu_latency;
  

What happen if we have several timer in one phase ? we will only get the last wake up latency, isn't it ?

Not sure I get where the problem is. Can you give me an example (and intended usage) of a phase with multiple timers? I don't seem to understand how that is supposed to work. :)

Below is an example of a timer that is used twice in the same phase: "tasks" : { "thread0" : { "instance" : 1, "loop" : -1, "run0" : 10000, "timer0" : { "ref" : "timerA", "period" : 20000 }, "run1" : 20000, "timer1" : { "ref" : "timerA", "period" : 40000 }, } },

More generally speaking, the log timing are saved per phase so the associated metrics should be per phase as well. With the example above, the fields c_period and the c_run give the last part of the phase.

Then, if we also record the wake up latency of sleep event, there are even more use case where several sleep and timer are used in a phase

On 21 November 2016 at 15:43, Juri Lelli juri.lelli@arm.com wrote:

On 21/11/16 15:08, Vincent Guittot wrote:

...

Le Monday 21 Nov 2016 à 12:26:03 (+0000), Juri Lelli a écrit :

...

On 21/11/16 10:33, Vincent Guittot wrote:

...

On 21 November 2016 at 10:28, Vincent Guittot vincent.guittot@linaro.org wrote:

...

On 17 November 2016 at 17:34, Juri Lelli juri.lelli@arm.com wrote:

[...]

...

...

...

    case rtapp_timer:
            {

•                   struct timespec t_period, t_now;
  

•                   struct timespec t_period, t_now, t_wu;
                    log_debug("timer %d ", event->duration);
  
                    t_period = usec_to_timespec(event->duration);
  

@@ -311,10 +311,15 @@ static int run_event(event_data_t *event, int dry_run,

                    rdata->res.timer.t_next = timespec_add(&rdata->res.timer.t_next, &t_period);
                    clock_gettime(CLOCK_MONOTONIC, &t_now);

•                   if (timespec_lower(&t_now, &rdata->res.timer.t_next))
  

•                   if (timespec_lower(&t_now, &rdata->res.timer.t_next)) {
                            clock_nanosleep(CLOCK_MONOTONIC, TIMER_ABSTIME, &rdata->res.timer.t_next, NULL);
  

•                   else
  

•                           clock_gettime(CLOCK_MONOTONIC, &t_now);
  

•                           t_wu = timespec_sub(&t_now, &rdata->res.timer.t_next);
  

•                           *wu_latency = timespec_to_usec(&t_wu);
  

You should add the same wake up latency metric for the sleep event

OK, will look into it.

...

...

...

•                   } else {
                            clock_gettime(CLOCK_MONOTONIC, &rdata->res.timer.t_next);
  

•                           *wu_latency = 0UL;
  

•                   }
            }
            break;
  

[...]

...

...

...

@@ -608,6 +616,7 @@ void *thread_body(void *arg) curr_timing->period = timespec_to_usec(&t_diff); curr_timing->duration = duration; curr_timing->perf = perf;

•           curr_timing->wu_latency = wu_latency;
  

What happen if we have several timer in one phase ? we will only get the last wake up latency, isn't it ?

Not sure I get where the problem is. Can you give me an example (and intended usage) of a phase with multiple timers? I don't seem to understand how that is supposed to work. :)

Below is an example of a timer that is used twice in the same phase: "tasks" : { "thread0" : { "instance" : 1, "loop" : -1, "run0" : 10000, "timer0" : { "ref" : "timerA", "period" : 20000 }, "run1" : 20000, "timer1" : { "ref" : "timerA", "period" : 40000 }, } },

Mmm, but these are IMHO two distinct phases and we should describe them as such (maybe add a check to disallow such a json description). It

I don't think that we should disallow this kind of description. IMHO, it is more readable than splitting it in several phase

Then, what about this: "phase0" : { "loop" : 2, "run0" : 10000, "timer0" : { "ref" : "timerA", "period" : 20000 }, "run1" : 20000, "timer1" : { "ref" : "timerA", "period" : 40000 }, }, "phase1" : { "loop" : 1, "run0" : 20000, "timer0" : { "ref" : "timerA", "period" : 400000 }, "run1" : 10000, "timer1" : { "ref" : "timerA", "period" : 20000 }, }

I can probably come we other description involving different timers as well. Just to say that we should not restrict how to use events in a phase.

seems that we only make confusion descriptions possible (and we complicate handling from a code pow).

It's just about an addition instead of overwriting the value. That's already the behavior for duration, period and perf and that will probably be the case c_run as well

...

More generally speaking, the log timing are saved per phase so the associated metrics should be per phase as well. With the example above, the fields c_period and the c_run give the last part of the phase.

Then, if we also record the wake up latency of sleep event, there are even more use case where several sleep and timer are used in a phase

On 22/11/16 10:21, Juri Lelli wrote:

On 22/11/16 10:41, Vincent Guittot wrote:

[...]

...

There also the c_run metrics in another patch, does it mean that you want only one run event per phase ?

Nope. That is broken in my current set. I'll fix that as you suggested (summing up the durations).

Which basically should result in the following right?

--->8--- src/rt-app.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/src/rt-app.c b/src/rt-app.c index 655c43e06a7d..bec511121d77 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -287,7 +287,7 @@ static int run_event(event_data_t *event, int dry_run, { struct timespec t_start, t_end; log_debug("run %d ", event->duration); - ldata->c_run = event->duration; + ldata->c_run += event->duration; clock_gettime(CLOCK_MONOTONIC, &t_start); *perf += loadwait(event->duration); clock_gettime(CLOCK_MONOTONIC, &t_end); --->8---

I was actually thinking that we should also sum up durations of all event that specify a duration (sleep, runtime, etc.) and maybe modify the log header as s/c_run/c_duration/ ?

On 22/11/16 11:50, Vincent Guittot wrote:

On 22 November 2016 at 11:41, Juri Lelli juri.lelli@arm.com wrote:

...

On 22/11/16 10:21, Juri Lelli wrote:

...

On 22/11/16 10:41, Vincent Guittot wrote:

[...]

...

...

There also the c_run metrics in another patch, does it mean that you want only one run event per phase ?

Nope. That is broken in my current set. I'll fix that as you suggested (summing up the durations).

Which basically should result in the following right?

--->8--- src/rt-app.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/src/rt-app.c b/src/rt-app.c index 655c43e06a7d..bec511121d77 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -287,7 +287,7 @@ static int run_event(event_data_t *event, int dry_run, { struct timespec t_start, t_end; log_debug("run %d ", event->duration);

•                   ldata->c_run = event->duration;
  

•                   ldata->c_run += event->duration;
                    clock_gettime(CLOCK_MONOTONIC, &t_start);
                    *perf += loadwait(event->duration);
                    clock_gettime(CLOCK_MONOTONIC, &t_end);
  

--->8---

I was actually thinking that we should also sum up durations of all event that specify a duration (sleep, runtime, etc.) and maybe modify the log header as s/c_run/c_duration/ ?

IMO adding runtime makes perfectly sense as commented in the related patch But not sleep which is a idle state just like timer

True.. but I was thinking that the best case slack will be affected also by sleep phases, so then if we compared the measured slack with the best one we should probably account for sleep events ?

e.g.,

|--- run 5000 ---|-- sleep 4000 --|--- run 5000 ---| |-----------------------------period 20000 -------------------| |----------| measured slack 6000

If we factor sleep duration in, we will compare 6000 (best case) vs 6000. If we don't, we will compare 10000 (best case) vs 6000, which ends up telling us that we ran slower for some reason, while instead we simply slept by constrution?

On 22/11/16 14:17, Vincent Guittot wrote:

On 22 November 2016 at 12:00, Juri Lelli juri.lelli@arm.com wrote:

...

On 22/11/16 11:50, Vincent Guittot wrote:

...

On 22 November 2016 at 11:41, Juri Lelli juri.lelli@arm.com wrote:

...

On 22/11/16 10:21, Juri Lelli wrote:

...

On 22/11/16 10:41, Vincent Guittot wrote:

[...]

...

...

There also the c_run metrics in another patch, does it mean that you want only one run event per phase ?

Nope. That is broken in my current set. I'll fix that as you suggested (summing up the durations).

Which basically should result in the following right?

--->8--- src/rt-app.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/src/rt-app.c b/src/rt-app.c index 655c43e06a7d..bec511121d77 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -287,7 +287,7 @@ static int run_event(event_data_t *event, int dry_run, { struct timespec t_start, t_end; log_debug("run %d ", event->duration);

•                   ldata->c_run = event->duration;
  

•                   ldata->c_run += event->duration;
                    clock_gettime(CLOCK_MONOTONIC, &t_start);
                    *perf += loadwait(event->duration);
                    clock_gettime(CLOCK_MONOTONIC, &t_end);
  

--->8---

I was actually thinking that we should also sum up durations of all event that specify a duration (sleep, runtime, etc.) and maybe modify the log header as s/c_run/c_duration/ ?

IMO adding runtime makes perfectly sense as commented in the related patch But not sleep which is a idle state just like timer

True.. but I was thinking that the best case slack will be affected also by sleep phases, so then if we compared the measured slack with the best one we should probably account for sleep events ?

e.g.,

|--- run 5000 ---|-- sleep 4000 --|--- run 5000 ---| |-----------------------------period 20000 -------------------| |----------| measured slack 6000

If we factor sleep duration in, we will compare 6000 (best case) vs 6000. If we don't, we will compare 10000 (best case) vs 6000, which ends up telling us that we ran slower for some reason, while instead we simply slept by constrution?

IIUC the slack metric represents the real "idle/sleep" time compared to what have been configured (timer duration minus duration of events in the time slot) Can't we also add a slack value for sleep events and add it slack value of timers in a phase to stay consistent with other metrics ?

so in the example above, the sack time will be 4000+6000 like the best case

Mmm, too me the slack it the time left before the next activation (of a periodic task) after all the events of the current activation have been completed. So, I'd say that we actually want to report 6000 in the example above. 'sleep' event is still something that we want to accomplish inside the current period, right? So it's like a 'runtime' (the freq invariant version of 'run').

On 22 November 2016 at 13:32, Juri Lelli juri.lelli@arm.com wrote:

On 22/11/16 11:54, Patrick Bellasi wrote:

...

On 22-Nov 12:01, Vincent Guittot wrote:

[...]

...

...

The example above is: start run 1 40ms after the start of run 0

I would say run1 starts 20ms after the start of run0, isn't it?

...

and start next event 20ms after the start of run1

mmm... not following here.

...

so you will not be impacted by the real duration of run0 and run1 (because of freq scaling or micro arch). Do this sequence 2 times then start the next sequence/phase

To me this is the expected behavior:

+-----+ +----------+ +-----+ +----------+ |r0 | |r1 | |r0 | |r1 | | | | | | | | | +-----------------------------------------------------------> 0 10 20 30 40 50 60 70 80 100 120 ^ ^ | | + + Timer0 Timer1

So, if we really need this level of flexibility we can add up periods as well (as Vincent was already saying) so that we end up we a row in the log for each phase reporting a "super-period" of 60ms.

If we agree that this makes sense, what we do for the slack? One possibility could be to start adding up there as well, so that the subslack of the first timer and the subslack of the second one are reflected in the slack reported in the per-phase row.

On thing that might be counter-intuitive looking at traces though is that if, for example, the first run executes for more that the first period (say 25 ms, e.g. frequency was low) it will report a -5ms slack which adds up with the second sub slack of r1 (which instead recovered and effectively executed for 20ms. So, now we report a 10ms overall slack, while in the trace we see a 15ms gap before the next event.

+------------+----------+ +-----+ +----------+ |r0 |r1 | |r0 | |r1 | | | | | | | | +-----------------------------------------------------------> 0 10 20 30 40 50 60 70 80 100 120 ^ ^ | | + + Timer0 Timer1

Oh, BTW, I also think that the following change is actually needed, otherwise the first run overshooting will influence the super-period.

Agree?

--->8--- From 52492c9ba118b686b76fcda05389a3a9c7c73120 Mon Sep 17 00:00:00 2001 From: Juri Lelli juri.lelli@arm.com Date: Tue, 22 Nov 2016 12:29:27 +0000 Subject: [PATCH] rt-app: don't let overshooting run phases affect timers

A run phase that overshoots might run for more that the next timer event. If that happens we still want for timers to not be affect by this happening.

Don't use current clock for setting the next timer event, always refer to t_first.

Signed-off-by: Juri Lelli juri.lelli@arm.com

src/rt-app.c | 1 - 1 file changed, 1 deletion(-)

diff --git a/src/rt-app.c b/src/rt-app.c index bec511121d77..36013758f718 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -338,7 +338,6 @@ static int run_event(event_data_t *event, int dry_run, t_wu = timespec_sub(&t_now, &rdata->res.timer.t_next); ldata->wu_latency = timespec_to_usec(&t_wu); } else {

•                           clock_gettime(CLOCK_MONOTONIC, &rdata->res.timer.t_next);
  

The 1st implementation didn't update t_next when timer has already expired. But then following timers were also noted as expired because the prev period has stolen time whereas the run time was correct. We faced the issue while testing frequency scaling policy: the governor was slow to react to the 1st period, the overshoot during this 1st period was so huge compared the margin of the use case than the next periods were already expired when the run has finished whereas the governor has reacted and increased freq to max. In fact, the delay generated by the 1st period was so huge that it was not compensated after the result was meaningless because 1 period was really wrong but the following one were also seen as wrong

As an example: run 9ms in a period of 10ms. Your platform starts at lowest OPP which is 10 time slower than max OPP. If the 1st run event takes something like 50ms (the time for the governor to react), we have an overshoot of 40ms. This means that even if we are now at max OPP and the run event really takes 9ms, the next 40 periods will be seen as wrong because we will set timer in the past.

                            ldata->wu_latency = 0UL;
                    }
            }

On 22/11/16 14:02, Juri Lelli wrote:

[...]

Since I think that both approaches might be useful to implement, why don't we add a "mode" : [absolute|relative] to timers and than we check the mode when executing the event to decide if we want to use current clock for t_next or keep t_first as reference?

Something like the following (on top of previous patch) maybe? --->8--- src/rt-app.c | 2 ++ src/rt-app_parse_config.c | 6 ++++++ src/rt-app_types.h | 1 + 3 files changed, 9 insertions(+)

diff --git a/src/rt-app.c b/src/rt-app.c index 36013758f718..e28d4f9e8ddc 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -338,6 +338,8 @@ static int run_event(event_data_t *event, int dry_run, t_wu = timespec_sub(&t_now, &rdata->res.timer.t_next); ldata->wu_latency = timespec_to_usec(&t_wu); } else { + if (rdata->res.timer.relative) + clock_gettime(CLOCK_MONOTONIC, &rdata->res.timer.t_next); ldata->wu_latency = 0UL; } } diff --git a/src/rt-app_parse_config.c b/src/rt-app_parse_config.c index b0f302e2ba25..fbc4612b2257 100644 --- a/src/rt-app_parse_config.c +++ b/src/rt-app_parse_config.c @@ -181,6 +181,7 @@ static int init_timer_resource(rtapp_resource_t *data, const rtapp_options_t *op { log_info(PIN3 "Init: %s timer", data->name); data->res.timer.init = 0; + data->res.timer.relative = 1; }

static int init_cond_resource(rtapp_resource_t *data, const rtapp_options_t *opts) @@ -489,6 +490,11 @@ parse_thread_event_data(char *name, struct json_object *obj, rdata = &(opts->resources[data->res]); ddata = &(opts->resources[data->dep]);

+ tmp = get_string_value_from(obj, "mode", TRUE, "relative"); + if (!strncmp(tmp, "absolute", strlen("absolute"))) + rdata->res.timer.relative = 0; + free(tmp); + log_info(PIN2 "type %d target %s [%d] period %d", data->type, rdata->name, rdata->index, data->duration); return; } diff --git a/src/rt-app_types.h b/src/rt-app_types.h index 60bd1e85d671..c9227b8ed6a1 100644 --- a/src/rt-app_types.h +++ b/src/rt-app_types.h @@ -87,6 +87,7 @@ struct _rtapp_signal { struct _rtapp_timer { struct timespec t_next; int init; + int relative; };

struct _rtapp_iomem_buf {

On 22/11/16 16:01, Vincent Guittot wrote:

On 22 November 2016 at 15:34, Juri Lelli juri.lelli@arm.com wrote:

...

On 22/11/16 14:02, Juri Lelli wrote:

[...]

...

Since I think that both approaches might be useful to implement, why don't we add a "mode" : [absolute|relative] to timers and than we check the mode when executing the event to decide if we want to use current clock for t_next or keep t_first as reference?

Yes being able to select between relative and absolute can make sense

...

Something like the following (on top of previous patch) maybe? --->8--- src/rt-app.c | 2 ++ src/rt-app_parse_config.c | 6 ++++++ src/rt-app_types.h | 1 + 3 files changed, 9 insertions(+)

diff --git a/src/rt-app.c b/src/rt-app.c index 36013758f718..e28d4f9e8ddc 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -338,6 +338,8 @@ static int run_event(event_data_t *event, int dry_run, t_wu = timespec_sub(&t_now, &rdata->res.timer.t_next); ldata->wu_latency = timespec_to_usec(&t_wu); } else {

•                           if (rdata->res.timer.relative)
  

•                                   clock_gettime(CLOCK_MONOTONIC, &rdata->res.timer.t_next);
                            ldata->wu_latency = 0UL;
                    }
            }
  

diff --git a/src/rt-app_parse_config.c b/src/rt-app_parse_config.c index b0f302e2ba25..fbc4612b2257 100644 --- a/src/rt-app_parse_config.c +++ b/src/rt-app_parse_config.c @@ -181,6 +181,7 @@ static int init_timer_resource(rtapp_resource_t *data, const rtapp_options_t *op { log_info(PIN3 "Init: %s timer", data->name); data->res.timer.init = 0;

•   data->res.timer.relative = 1;
  

}

static int init_cond_resource(rtapp_resource_t *data, const rtapp_options_t *opts) @@ -489,6 +490,11 @@ parse_thread_event_data(char *name, struct json_object *obj, rdata = &(opts->resources[data->res]); ddata = &(opts->resources[data->dep]);

•           tmp = get_string_value_from(obj, "mode", TRUE, "relative");
  

Ok so the timer event will look like absolute mode: "timer1" : { "ref" : "timerA", "period" : 20000, "mode" : "absolute" }

relative mode: "timer1" : { "ref" : "timerA", "period" : 20000, "mode" : "relative" } or "timer1" : { "ref" : "timerA", "period" : 20000 } for keeping current behavior

Looks ok to me

Yep. Will add the patch in v3.

On 17 November 2016 at 17:34, Juri Lelli juri.lelli@arm.com wrote:

A big run duration can cause load_count to overflow. Fix this issue by running the workload in bursts of 1 sec each.

Signed-off-by: Juri Lelli juri.lelli@arm.com

Acked-by: Vincent Guittot vincent.guittot@linaro.org

---

src/rt-app.c | 22 ++++++++++++++++++++-- 1 file changed, 20 insertions(+), 2 deletions(-)

diff --git a/src/rt-app.c b/src/rt-app.c index bce004bc91a3..dc84e2cc22ff 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -48,10 +48,11 @@ static ftrace_data_t ft_data = {

• Function: to do some useless operation.
• TODO: improve the waste loop with more heavy functions

*/ -void waste_cpu_cycles(int load_loops) +void waste_cpu_cycles(unsigned long long load_loops) { double param, result;

•   double n, i;
  

•   double n;
  

•   unsigned long long i;
  
    param = 0.95;
    n = 4;
  

@@ -175,7 +176,24 @@ int calibrate_cpu_cycles(int clock) static inline unsigned long loadwait(unsigned long exec) { unsigned long load_count;

•   unsigned long secs;
  

•   int i;
  

•   /*
  

•    * If exec is still too big, let's run it in bursts
  

•    * so that we don't overflow load_count.
  

•    */
  

•   secs = exec / 1000000;
  
  

•   for (i = 0; i < secs; i++) {
  

•           load_count = 1000000000/p_load;
  

•           waste_cpu_cycles(load_count);
  

•           exec -= 1000000;
  

•   }
  

•   /*
  

•    * Run for the remainig exec (if any).
  

•    */
    load_count = (exec * 1000)/p_load;
    waste_cpu_cycles(load_count);
  
  

-- 2.10.0

On 17 November 2016 at 17:34, Juri Lelli juri.lelli@arm.com wrote:

It is handy to have the configured period directly in logs. Add it there.

Signed-off-by: Juri Lelli juri.lelli@arm.com

src/rt-app.c | 22 ++++++++++++++-------- src/rt-app_types.h | 1 + src/rt-app_utils.c | 5 +++-- 3 files changed, 18 insertions(+), 10 deletions(-)

diff --git a/src/rt-app.c b/src/rt-app.c index dc84e2cc22ff..3dc4f6e1adaf 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -238,7 +238,8 @@ static void memload(unsigned long count, struct _rtapp_iomem_buf *iomem)

static int run_event(event_data_t *event, int dry_run, unsigned long *perf, unsigned long *duration, rtapp_resource_t *resources,

•           struct timespec *t_first, unsigned long *wu_latency, long *slack)
  

•           struct timespec *t_first, unsigned long *wu_latency, long *slack,
  

•           unsigned long *c_period)
  

{ rtapp_resource_t *rdata = &(resources[event->res]); rtapp_resource_t *ddata = &(resources[event->dep]); @@ -321,6 +322,7 @@ static int run_event(event_data_t *event, int dry_run, log_debug("timer %d ", event->duration);

                    t_period = usec_to_timespec(event->duration);

•                   *c_period = event->duration;
  

Like for c_run, we can have several periods in a phase and the c_period is per phase not per event so we should probably add them and reset the period when starting a new phase

                    if (rdata->res.timer.init == 0) {
                            rdata->res.timer.init = 1;

@@ -379,7 +381,8 @@ int run(int ind, phase_data_t *pdata, unsigned long *duration, rtapp_resource_t *resources, struct timespec *t_first, unsigned long *wu_latency,

•           long *slack)
  

•           long *slack,
  

•           unsigned long *c_period)
  

{ event_data_t *events = pdata->events; int nbevents = pdata->nbevents; @@ -397,7 +400,8 @@ int run(int ind, phase_data_t *pdata, unsigned long *duration, "[%d] executing %d", ind, i); lock += run_event(&events[i], !continue_running, &perf,

•                             duration, resources, t_first, wu_latency, slack);
  

•                             duration, resources, t_first, wu_latency, slack,
  

•                             c_period);
    }
  
    return perf;
  

@@ -445,7 +449,7 @@ void *thread_body(void *arg) struct sched_param param; struct timespec t_start, t_end, t_first; unsigned long t_start_usec;

•   unsigned long perf, duration, wu_latency;
  

•   unsigned long perf, duration, wu_latency, c_period;
    long slack;
    timing_point_t *curr_timing;
    timing_point_t *timings;
  

@@ -586,9 +590,10 @@ void *thread_body(void *arg)

    log_notice("[%d] starting thread ...\n", data->ind);

•   fprintf(data->log_handler, "%s %8s %8s %8s %15s %15s %15s %10s %10s\n",
  

•   fprintf(data->log_handler, "%s %8s %8s %8s %15s %15s %15s %10s %10s %8s\n",
                               "#idx", "perf", "run", "period",
  

•                              "start", "end", "rel_st", "wu_lat", "slack");
  

•                              "start", "end", "rel_st", "wu_lat", "slack",
  

•                              "c_prd");
  
    if (opts.ftrace)
            log_ftrace(ft_data.marker_fd, "[%d] starts", data->ind);
  

@@ -619,10 +624,10 @@ void *thread_body(void *arg) log_ftrace(ft_data.marker_fd, "[%d] begins loop %d phase %d step %d", data->ind, i, j, loop); log_debug("[%d] begins loop %d phase %d step %d", data->ind, i, j, loop);;

•           duration = wu_latency = slack = 0;
  

•           duration = wu_latency = slack = c_period = 0;
            clock_gettime(CLOCK_MONOTONIC, &t_start);
            perf = run(data->ind, pdata, &duration, *(data->resources),
  

•                           &t_first, &wu_latency, &slack);
  

•                           &t_first, &wu_latency, &slack, &c_period);
            clock_gettime(CLOCK_MONOTONIC, &t_end);
  
            if (timings)
  

@@ -642,6 +647,7 @@ void *thread_body(void *arg) curr_timing->perf = perf; curr_timing->wu_latency = wu_latency; curr_timing->slack = slack;

•           curr_timing->c_period = c_period;
  
            if (opts.logsize && !timings)
                    log_timing(data->log_handler, curr_timing);
  

diff --git a/src/rt-app_types.h b/src/rt-app_types.h index 0570e7b5ad3e..0ec8781562ee 100644 --- a/src/rt-app_types.h +++ b/src/rt-app_types.h @@ -191,6 +191,7 @@ typedef struct _timing_point_t { unsigned long perf; unsigned long duration; unsigned long period;

•   unsigned long c_period;
    unsigned long wu_latency;
    long slack;
    __u64 start_time;
  

diff --git a/src/rt-app_utils.c b/src/rt-app_utils.c index a1a7c05d202e..e7cd8a83cec7 100644 --- a/src/rt-app_utils.c +++ b/src/rt-app_utils.c @@ -140,7 +140,7 @@ void log_timing(FILE *handler, timing_point_t *t) { fprintf(handler,

•           "%4d %8lu %8lu %8lu %15llu %15llu %15llu %10lu %10ld",
  

•           "%4d %8lu %8lu %8lu %15llu %15llu %15llu %10lu %10ld %8lu",
            t->ind,
            t->perf,
            t->duration,
  

@@ -149,7 +149,8 @@ log_timing(FILE *handler, timing_point_t *t) t->end_time, t->rel_start_time, t->wu_latency,

•           t->slack
  

•           t->slack,
  

•           t->c_period
    );
    fprintf(handler, "\n");
  

}

2.10.0

On 17 November 2016 at 17:34, Juri Lelli juri.lelli@arm.com wrote:

This is to avoid cases where the last row can contain bogus values.

Signed-off-by: Juri Lelli juri.lelli@arm.com

Acked-by: Vincent Guittot vincent.guittot@linaro.org

---

src/rt-app.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/src/rt-app.c b/src/rt-app.c index 3dc4f6e1adaf..182110b9c3ec 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -649,7 +649,7 @@ void *thread_body(void *arg) curr_timing->slack = slack; curr_timing->c_period = c_period;

•           if (opts.logsize && !timings)
  

•           if (opts.logsize && !timings && continue_running)
                    log_timing(data->log_handler, curr_timing);
  
            if (opts.ftrace)
  

-- 2.10.0

On 18/11/16 16:43, Vincent Guittot wrote:

On 17 November 2016 at 17:34, Juri Lelli juri.lelli@arm.com wrote:

...

Don't explicitly manage start/stop of tracing, but assume that the caller does that before starting rt-app. This helps if the caller wants more padding before/after an rt-app execution.

In case tracing is not started and ftrace is enable in the json configuration, rt-app will fail to start.

Signed-off-by: Juri Lelli juri.lelli@arm.com

src/rt-app.c | 5 +---- 1 file changed, 1 insertion(+), 4 deletions(-)

diff --git a/src/rt-app.c b/src/rt-app.c index 2354d423bcd2..2c6df5251ebe 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -430,9 +430,8 @@ shutdown(int sig) }

    if (opts.ftrace) {

•           log_notice("stopping ftrace");
            log_ftrace(ft_data.marker_fd, "main ends\n");
  

•           log_ftrace(ft_data.trace_fd, "0");
  

•           log_notice("deconfiguring ftrace");
  

...

            close(ft_data.trace_fd);

you can remove it as well as the open and all reference to trace_fd which is not used anymore AFAICT

...

            close(ft_data.marker_fd);
    }

@@ -745,7 +744,6 @@ int main(int argc, char* argv[]) exit(EXIT_FAILURE); }

•           log_ftrace(ft_data.trace_fd, "1");
            log_ftrace(ft_data.marker_fd, "main creates threads\n");
    }
  
  

@@ -937,7 +935,6 @@ int main(int argc, char* argv[]) if (opts.ftrace) { log_notice("stopping ftrace");

you can remove this log

...

            log_ftrace(ft_data.marker_fd, "main ends\n");

•           log_ftrace(ft_data.trace_fd, "0");
            close(ft_data.trace_fd);
  

ditto

Right. I'll update accordingly.

Best,

- Juri

On 17 November 2016 at 17:34, Juri Lelli juri.lelli@arm.com wrote:

Add a new thread property called 'delay' with which the initial starting time of a thread can be delayed. Parameter is expressed in usec.

Usage is:

"tasks" : { "thread0" : { ... "delay" : 1000000, ... } }

Signed-off-by: Juri Lelli juri.lelli@arm.com

Acked-by: Vincent Guittot vincent.guittot@linaro.org

---

doc/tutorial.txt | 3 +++ src/rt-app.c | 10 ++++++++++ src/rt-app_parse_config.c | 5 +++++ src/rt-app_types.h | 2 ++ 4 files changed, 20 insertions(+)

diff --git a/doc/tutorial.txt b/doc/tutorial.txt index 78cd1fe0e2e2..f88c69f29c1d 100644 --- a/doc/tutorial.txt +++ b/doc/tutorial.txt @@ -200,6 +200,9 @@ class. Default value is period. The unit is usec.

• cpus: Array of Integer. Define the CPU affinity of the thread. Default

value is all CPUs of the system. An example : "cpus" : [0, 2, 3]

+* delay: Integer. Initial delay before a thread starts execution. The unit +is usec.

• phases: Object. The phases object described TBF

If there is only 1 phase, the sequence of events can be directly put in the diff --git a/src/rt-app.c b/src/rt-app.c index 2c6df5251ebe..4eaa693f7053 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -612,6 +612,16 @@ void *thread_body(void *arg) } } #endif

•   if (data->delay > 0) {
  

•           struct timespec delay = usec_to_timespec(data->delay);
  

•           log_debug("initial delay %d ", data->delay);
  

•           t_first = timespec_add(&t_first, &delay);
  

•           clock_nanosleep(CLOCK_MONOTONIC, TIMER_ABSTIME, &t_first,
  

•                           NULL);
  

•   }
  

•   i = j = loop = idx = 0;
  
    while (continue_running && (i != data->loop)) {
  

diff --git a/src/rt-app_parse_config.c b/src/rt-app_parse_config.c index c59b56290bbf..b0f302e2ba25 100644 --- a/src/rt-app_parse_config.c +++ b/src/rt-app_parse_config.c @@ -689,6 +689,11 @@ parse_thread_data(char *name, struct json_object *obj, int index, } log_info(PIN "key: cpus %s", data->cpuset_str);

•   /* initial delay */
  

•   data->delay = get_int_value_from(obj, "delay", TRUE, 0);
  

•   if (data->delay < 0)
  

•           data->delay = 0;
  

•   /* Get phases */
    phases_obj = get_in_object(obj, "phases", TRUE);
    if (phases_obj) {
  

diff --git a/src/rt-app_types.h b/src/rt-app_types.h index 5a1d87c24e78..60bd1e85d671 100644 --- a/src/rt-app_types.h +++ b/src/rt-app_types.h @@ -149,6 +149,8 @@ typedef struct _thread_data_t { char sched_policy_descr[RTAPP_POLICY_DESCR_LENGTH]; int sched_prio;

•   unsigned long delay;
  

#ifdef DLSCHED struct sched_attr dl_params;

#endif

2.10.0