Hi all,
this is an attempt to align and finally merge Linaro's and ARM's versions of rt-app (so that we make the whole story more clean and sound and possibly facilitate adoption by even more people). Apologies for not doing this before and not being responsive to Vincent and Pi-Cheng previous attemps; turns out that I never had really the time to seriously looking at this until now.
Anyway, I've already pushed Linaro's current tree on scheduler-tools/rt-app master[1] (and added Vincent as co-maintainer); this series is based on top of that. These patches represent the deltas between what we currently use (for EAS evaluation and LISA tooling) and Linaro's version.
Please have a look and comment. I slightly tested them and couldn't find any problems yet; please, do the same.
Thanks a lot,
- Juri
[1] https://github.com/scheduler-tools/rt-app/commits/master
Juri Lelli (13): doc: clarify example for config step rt-app: fix compile warnings rt-app: add a t_zero to which every tasks has to refer rt-app: add wake-up latency to the log metrics rt-app: add slack to log metrics rt-app: add 'delay' phase rt-app: fix batch tasks rt-app: add 'configured period' to log metrics rt-app: write logs only if continue_running is set rt-app: refactor log data to reduce the number of parameters of run() rt-app: move wu_lat to the end of the log rt-app: make c_prd c_period and enlarge it rt-app: add configured run (c_run) to log metrics
doc/tutorial.txt | 25 ++++++++++ libdl/dl_syscalls.h | 4 +- src/rt-app.c | 113 ++++++++++++++++++++++++++++++++++++---------- src/rt-app_args.h | 3 -- src/rt-app_parse_config.c | 6 ++- src/rt-app_parse_config.h | 2 + src/rt-app_types.h | 14 ++++++ src/rt-app_utils.c | 23 ++++++++-- src/rt-app_utils.h | 6 +++ 9 files changed, 162 insertions(+), 34 deletions(-)
Add detailed example for static cross-compile of rt-app.
Signed-off-by: Juri Lelli juri.lelli@arm.com --- doc/tutorial.txt | 25 +++++++++++++++++++++++++ 1 file changed, 25 insertions(+)
diff --git a/doc/tutorial.txt b/doc/tutorial.txt index 100a2df068c6..78cd1fe0e2e2 100644 --- a/doc/tutorial.txt +++ b/doc/tutorial.txt @@ -43,6 +43,31 @@ export ac_cv_lib_json_c_json_object_from_file=yes ./configure --host=aarch64-linux-gnu LDFLAGS=" --static -L<path to parent of json repo>/json-c/. libs/" CFLAGS="-I<path to parent of json repo>" --with-deadline make
+e.g, with a directory structure like the following: + +$ tree -d +. +├── autom4te.cache +├── build +├── build-aux +├── doc +│ └── examples +│ ├── cpufreq_governor_efficiency +│ ├── merge +│ └── tutorial +├── json-c +│ ├── autom4te.cache +│ ├── doc +│ │ └── html +│ └── tests +├── libdl +├── m4 +└── src + +the configure step becomes + +./configure --host=aarch64-linux-gnu LDFLAGS="--static -L./../json-c/." CFLAGS="-I./.." --with-deadline + **** json file skeleton ****
The json file that describes a workload is made on 3 main objects: tasks,
On 11 November 2016 at 10:17, Juri Lelli juri.lelli@arm.com wrote:
Add detailed example for static cross-compile of rt-app.
Signed-off-by: Juri Lelli juri.lelli@arm.com
Acked-by: Vincent Guittot vincent.guittot@linaro.org
doc/tutorial.txt | 25 +++++++++++++++++++++++++ 1 file changed, 25 insertions(+)
diff --git a/doc/tutorial.txt b/doc/tutorial.txt index 100a2df068c6..78cd1fe0e2e2 100644 --- a/doc/tutorial.txt +++ b/doc/tutorial.txt @@ -43,6 +43,31 @@ export ac_cv_lib_json_c_json_object_from_file=yes ./configure --host=aarch64-linux-gnu LDFLAGS=" --static -L<path to parent of json repo>/json-c/. libs/" CFLAGS="-I<path to parent of json repo>" --with-deadline make
+e.g, with a directory structure like the following:
+$ tree -d +. +├── autom4te.cache +├── build +├── build-aux +├── doc +│ └── examples +│ ├── cpufreq_governor_efficiency +│ ├── merge +│ └── tutorial +├── json-c +│ ├── autom4te.cache +│ ├── doc +│ │ └── html +│ └── tests +├── libdl +├── m4 +└── src
+the configure step becomes
+./configure --host=aarch64-linux-gnu LDFLAGS="--static -L./../json-c/." CFLAGS="-I./.." --with-deadline
**** json file skeleton ****
The json file that describes a workload is made on 3 main objects: tasks,
2.10.0
Fix various compilation warnings in one go.
Signed-off-by: Juri Lelli juri.lelli@arm.com --- 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 | 4 ++-- src/rt-app_utils.h | 3 +++ 6 files changed, 12 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..fc01f944235e 100644 --- a/src/rt-app_utils.c +++ b/src/rt-app_utils.c @@ -253,7 +253,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,7 +274,7 @@ 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); 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
On 11 November 2016 at 10:17, Juri Lelli juri.lelli@arm.com wrote:
Fix various compilation warnings in one go.
Signed-off-by: Juri Lelli juri.lelli@arm.com
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 | 4 ++-- src/rt-app_utils.h | 3 +++ 6 files changed, 12 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..fc01f944235e 100644 --- a/src/rt-app_utils.c +++ b/src/rt-app_utils.c @@ -253,7 +253,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,7 +274,7 @@ 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);
This remove the warning but the ret is useless, we should better loop on the write until we have written all data or an error happens
free(tmp); 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 14/11/16 16:02, Vincent Guittot wrote:
On 11 November 2016 at 10:17, Juri Lelli juri.lelli@arm.com wrote:
[...]
@@ -274,7 +274,7 @@ 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);This remove the warning but the ret is useless, we should better loop on the write until we have written all data or an error happens
Right, something like this better?
--- src/rt-app_utils.c | 7 +++++++ 1 file changed, 7 insertions(+)
diff --git a/src/rt-app_utils.c b/src/rt-app_utils.c index 0791291bcd81..fa574935fbaa 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 @@ -291,6 +293,11 @@ void ftrace_write(int mark_fd, const char *fmt, ...) if (n > -1 && n < size) { ret = write(mark_fd, tmp, n); free(tmp); + if (ret < 0) { + log_error("Cannot write mark_fd: %s\n", + strerror(errno)); + exit(EXIT_FAILURE); + } return; }
On 17 November 2016 at 11:35, Juri Lelli juri.lelli@arm.com wrote:
On 14/11/16 16:02, Vincent Guittot wrote:
On 11 November 2016 at 10:17, Juri Lelli juri.lelli@arm.com wrote:
[...]
@@ -274,7 +274,7 @@ 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);This remove the warning but the ret is useless, we should better loop on the write until we have written all data or an error happens
Right, something like this better?
src/rt-app_utils.c | 7 +++++++ 1 file changed, 7 insertions(+)
diff --git a/src/rt-app_utils.c b/src/rt-app_utils.c index 0791291bcd81..fa574935fbaa 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 @@ -291,6 +293,11 @@ void ftrace_write(int mark_fd, const char *fmt, ...) if (n > -1 && n < size) { ret = write(mark_fd, tmp, n);
ret can be different than n meaning that all data have not been written
free(tmp);
if (ret < 0) {log_error("Cannot write mark_fd: %s\n",strerror(errno));exit(EXIT_FAILURE);} return; }
On 17/11/16 15:54, Vincent Guittot wrote:
On 17 November 2016 at 11:35, Juri Lelli juri.lelli@arm.com wrote:
On 14/11/16 16:02, Vincent Guittot wrote:
On 11 November 2016 at 10:17, Juri Lelli juri.lelli@arm.com wrote:
[...]
@@ -274,7 +274,7 @@ 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);This remove the warning but the ret is useless, we should better loop on the write until we have written all data or an error happens
Right, something like this better?
src/rt-app_utils.c | 7 +++++++ 1 file changed, 7 insertions(+)
diff --git a/src/rt-app_utils.c b/src/rt-app_utils.c index 0791291bcd81..fa574935fbaa 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 @@ -291,6 +293,11 @@ void ftrace_write(int mark_fd, const char *fmt, ...) if (n > -1 && n < size) { ret = write(mark_fd, tmp, n);
ret can be different than n meaning that all data have not been written
Right. Do you think we could safely ignore such cases (as we've done since now) and maybe report them for debug purposes only?
--- src/rt-app_utils.c | 2 ++ 1 file changed, 2 insertions(+)
diff --git a/src/rt-app_utils.c b/src/rt-app_utils.c index 8d2c8fd4f324..c40eed55109d 100644 --- a/src/rt-app_utils.c +++ b/src/rt-app_utils.c @@ -292,6 +292,8 @@ void ftrace_write(int mark_fd, const char *fmt, ...) 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; }
On 17 November 2016 at 16:46, Juri Lelli juri.lelli@arm.com wrote:
On 17/11/16 15:54, Vincent Guittot wrote:
On 17 November 2016 at 11:35, Juri Lelli juri.lelli@arm.com wrote:
On 14/11/16 16:02, Vincent Guittot wrote:
On 11 November 2016 at 10:17, Juri Lelli juri.lelli@arm.com wrote:
[...]
@@ -274,7 +274,7 @@ 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);This remove the warning but the ret is useless, we should better loop on the write until we have written all data or an error happens
Right, something like this better?
src/rt-app_utils.c | 7 +++++++ 1 file changed, 7 insertions(+)
diff --git a/src/rt-app_utils.c b/src/rt-app_utils.c index 0791291bcd81..fa574935fbaa 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 @@ -291,6 +293,11 @@ void ftrace_write(int mark_fd, const char *fmt, ...) if (n > -1 && n < size) { ret = write(mark_fd, tmp, n);
ret can be different than n meaning that all data have not been written
Right. Do you think we could safely ignore such cases (as we've done since now) and maybe report them for debug purposes only?
Yes at least report it for debug purpose but we should fix that to prevent lost of data in a next step
src/rt-app_utils.c | 2 ++ 1 file changed, 2 insertions(+)
diff --git a/src/rt-app_utils.c b/src/rt-app_utils.c index 8d2c8fd4f324..c40eed55109d 100644 --- a/src/rt-app_utils.c +++ b/src/rt-app_utils.c @@ -292,6 +292,8 @@ void ftrace_write(int mark_fd, const char *fmt, ...) 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; }
Also a barrier is added so that execution starts at the same instant for everybody.
Signed-off-by: Juri Lelli juri.lelli@arm.com --- src/rt-app.c | 29 ++++++++++++++++++++++------- 1 file changed, 22 insertions(+), 7 deletions(-)
diff --git a/src/rt-app.c b/src/rt-app.c index 211dd77da98f..51aadf480a3f 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,17 @@ void *thread_body(void *arg) } }
+ if (data->ind == 0) { + 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 +586,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 +675,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);
On 11 November 2016 at 10:17, 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
src/rt-app.c | 29 ++++++++++++++++++++++------- 1 file changed, 22 insertions(+), 7 deletions(-)
diff --git a/src/rt-app.c b/src/rt-app.c index 211dd77da98f..51aadf480a3f 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,17 @@ void *thread_body(void *arg) } }
if (data->ind == 0) {clock_gettime(CLOCK_MONOTONIC, &t_zero);if (opts.ftrace)log_ftrace(ft_data.marker_fd,"[%d] sets zero time",data->ind);}
Only the 1st thread (data->ind == 0) is going to set t_zero. It's worth adding a comment explaining the mecanism that 1st thread set t_zero and other thread sync with this timestamp
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 +586,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 +675,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 14/11/16 16:50, Vincent Guittot wrote:
On 11 November 2016 at 10:17, Juri Lelli juri.lelli@arm.com wrote:
[...]
if (data->ind == 0) {clock_gettime(CLOCK_MONOTONIC, &t_zero);if (opts.ftrace)log_ftrace(ft_data.marker_fd,"[%d] sets zero time",data->ind);}Only the 1st thread (data->ind == 0) is going to set t_zero. It's worth adding a comment explaining the mecanism that 1st thread set t_zero and other thread sync with this timestamp
Done.
Thanks,
- Juri
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 51aadf480a3f..c620985d9b44 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; @@ -553,7 +559,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); @@ -584,9 +592,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) @@ -604,6 +612,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 fc01f944235e..0bdc66f60973 100644 --- a/src/rt-app_utils.c +++ b/src/rt-app_utils.c @@ -132,14 +132,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"); }
Add measured slack to log metrics; it is meausured as the interval of time between the end of the current activation and the begin of the next one.
Signed-off-by: Juri Lelli juri.lelli@arm.com --- src/rt-app.c | 23 +++++++++++++++-------- src/rt-app_types.h | 1 + src/rt-app_utils.c | 11 +++++++++-- src/rt-app_utils.h | 3 +++ 4 files changed, 28 insertions(+), 10 deletions(-)
diff --git a/src/rt-app.c b/src/rt-app.c index c620985d9b44..77d682acf3db 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, unsigned long *wu_latency) + struct timespec *t_first, unsigned long *wu_latency, long *slack) { 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, t_wu; + struct timespec t_period, t_now, t_wu, t_slack; log_debug("timer %d ", event->duration);
t_period = usec_to_timespec(event->duration); @@ -311,6 +311,8 @@ 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); + t_slack = timespec_sub(&rdata->res.timer.t_next, &t_now); + *slack = timespec_to_usec_long(&t_slack); if (timespec_lower(&t_now, &rdata->res.timer.t_next)) { clock_nanosleep(CLOCK_MONOTONIC, TIMER_ABSTIME, &rdata->res.timer.t_next, NULL); clock_gettime(CLOCK_MONOTONIC, &t_now); @@ -358,7 +360,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, - unsigned long *wu_latency) + unsigned long *wu_latency, + long *slack) { event_data_t *events = pdata->events; int nbevents = pdata->nbevents; @@ -375,7 +378,8 @@ 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, wu_latency); + lock += run_event(&events[i], !continue_running, &perf, + duration, resources, t_first, wu_latency, slack); }
return perf; @@ -424,6 +428,7 @@ void *thread_body(void *arg) struct timespec t_start, t_end, t_first; unsigned long t_start_usec; unsigned long perf, duration, wu_latency; + long slack; timing_point_t *curr_timing; timing_point_t *timings; timing_point_t tmp_timing; @@ -559,9 +564,9 @@ 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\n", + fprintf(data->log_handler, "%s %8s %8s %8s %15s %15s %15s %10s %10s\n", "#idx", "perf", "run", "period", - "start", "end", "rel_st", "wu_lat"); + "start", "end", "rel_st", "wu_lat", "slack");
if (opts.ftrace) log_ftrace(ft_data.marker_fd, "[%d] starts", data->ind); @@ -592,9 +597,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 = 0; + duration = wu_latency = slack = 0; clock_gettime(CLOCK_MONOTONIC, &t_start); - perf = run(data->ind, pdata, &duration, *(data->resources), &t_first, &wu_latency); + perf = run(data->ind, pdata, &duration, *(data->resources), + &t_first, &wu_latency, &slack); clock_gettime(CLOCK_MONOTONIC, &t_end);
if (timings) @@ -613,6 +619,7 @@ void *thread_body(void *arg) curr_timing->duration = duration; curr_timing->perf = perf; curr_timing->wu_latency = wu_latency; + curr_timing->slack = slack;
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 4c20f43cb627..0570e7b5ad3e 100644 --- a/src/rt-app_types.h +++ b/src/rt-app_types.h @@ -192,6 +192,7 @@ typedef struct _timing_point_t { unsigned long duration; unsigned long period; unsigned long wu_latency; + long slack; __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 0bdc66f60973..45cf26a964e2 100644 --- a/src/rt-app_utils.c +++ b/src/rt-app_utils.c @@ -33,6 +33,12 @@ timespec_to_usec_ull(struct timespec *ts) return llround((ts->tv_sec * 1E9 + ts->tv_nsec) / 1000.0); }
+long +timespec_to_usec_long(struct timespec *ts) +{ + return round((ts->tv_sec * 1E9 + ts->tv_nsec) / 1000.0); +} + #ifdef DLSCHED __u64 timespec_to_nsec(struct timespec *ts) @@ -132,7 +138,7 @@ void log_timing(FILE *handler, timing_point_t *t) { fprintf(handler, - "%4d %8lu %8lu %8lu %15llu %15llu %15llu %10lu", + "%4d %8lu %8lu %8lu %15llu %15llu %15llu %10lu %10ld", t->ind, t->perf, t->duration, @@ -140,7 +146,8 @@ log_timing(FILE *handler, timing_point_t *t) t->start_time, t->end_time, t->rel_start_time, - t->wu_latency + t->wu_latency, + t->slack ); fprintf(handler, "\n"); } diff --git a/src/rt-app_utils.h b/src/rt-app_utils.h index a41d8ad205aa..6a8d921d1321 100644 --- a/src/rt-app_utils.h +++ b/src/rt-app_utils.h @@ -92,6 +92,9 @@ timespec_to_usec(struct timespec *ts); unsigned long long timespec_to_usec_ull(struct timespec *ts);
+long +timespec_to_usec_long(struct timespec *ts); + struct timespec usec_to_timespec(unsigned long usec);
Add a new phase called 'delay' with which the initial starting time of a task can be delayed. Parameter is expressed in usec.
Usage is:
"phases": { "p0": { "delay": 1500000 }, ... other phases ... }
Signed-off-by: Juri Lelli juri.lelli@arm.com --- src/rt-app.c | 9 +++++++++ src/rt-app_parse_config.c | 6 +++++- src/rt-app_types.h | 1 + src/rt-app_utils.c | 5 +++++ 4 files changed, 20 insertions(+), 1 deletion(-)
diff --git a/src/rt-app.c b/src/rt-app.c index 77d682acf3db..76a5c11b365c 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -297,6 +297,15 @@ static int run_event(event_data_t *event, int dry_run, *duration += timespec_to_usec(&t_end); } break; + case rtapp_delay: + { + struct timespec delay = usec_to_timespec(event->duration); + log_debug("delay %d ", event->duration); + + *t_first = timespec_add(t_first, &delay); + clock_nanosleep(CLOCK_MONOTONIC, TIMER_ABSTIME, t_first, NULL); + } + break; case rtapp_timer: { struct timespec t_period, t_now, t_wu, t_slack; diff --git a/src/rt-app_parse_config.c b/src/rt-app_parse_config.c index c59b56290bbf..f8d0f52f3ab9 100644 --- a/src/rt-app_parse_config.c +++ b/src/rt-app_parse_config.c @@ -339,7 +339,8 @@ parse_thread_event_data(char *name, struct json_object *obj, int i;
if (!strncmp(name, "run", strlen("run")) || - !strncmp(name, "sleep", strlen("sleep"))) { + !strncmp(name, "sleep", strlen("sleep")) || + !strncmp(name, "delay", strlen("delay"))) {
if (!json_object_is_type(obj, json_type_int)) goto unknown_event; @@ -350,6 +351,8 @@ parse_thread_event_data(char *name, struct json_object *obj, data->type = rtapp_sleep; else if (!strncmp(name, "runtime", strlen("runtime"))) data->type = rtapp_runtime; + else if (!strncmp(name, "delay", strlen("delay"))) + data->type = rtapp_delay; else data->type = rtapp_run;
@@ -562,6 +565,7 @@ static char *events[] = { "sleep", "runtime", "run", + "delay", "timer", "suspend", "resume", diff --git a/src/rt-app_types.h b/src/rt-app_types.h index 0570e7b5ad3e..cb7c9242f82e 100644 --- a/src/rt-app_types.h +++ b/src/rt-app_types.h @@ -58,6 +58,7 @@ typedef enum resource_t rtapp_signal, rtapp_broadcast, rtapp_sleep, + rtapp_delay, rtapp_run, rtapp_sig_and_wait, rtapp_lock, diff --git a/src/rt-app_utils.c b/src/rt-app_utils.c index 45cf26a964e2..eeb8e7b04e91 100644 --- a/src/rt-app_utils.c +++ b/src/rt-app_utils.c @@ -215,6 +215,8 @@ string_to_resource(const char *name, resource_t *resource) *resource = rtapp_sig_and_wait; else if (strcmp(name, "sleep") == 0) *resource = rtapp_sleep; + else if (strcmp(name, "delay") == 0) + *resource = rtapp_delay; else if (strcmp(name, "run") == 0) *resource = rtapp_run; else if (strcmp(name, "timer") == 0) @@ -246,6 +248,9 @@ resource_to_string(resource_t resource, char *resource_name) case rtapp_sleep: strcpy(resource_name, "sleep"); break; + case rtapp_delay: + strcpy(resource_name, "delay"); + break; case rtapp_run: strcpy(resource_name, "run"); break;
On 11 November 2016 at 10:17, Juri Lelli juri.lelli@arm.com wrote:
Add a new phase called 'delay' with which the initial starting time of a task can be delayed. Parameter is expressed in usec.
Could you add a description of the command in the tutorial.txt document ?
Usage is:
"phases": { "p0": { "delay": 1500000
}, ... other phases ...}
This delay seems to be more a thread's properties than a event : It should be called only once in a dedicated phase You should better parse it and set t_first in the parse_thread_data
Signed-off-by: Juri Lelli juri.lelli@arm.com
src/rt-app.c | 9 +++++++++ src/rt-app_parse_config.c | 6 +++++- src/rt-app_types.h | 1 + src/rt-app_utils.c | 5 +++++ 4 files changed, 20 insertions(+), 1 deletion(-)
diff --git a/src/rt-app.c b/src/rt-app.c index 77d682acf3db..76a5c11b365c 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -297,6 +297,15 @@ static int run_event(event_data_t *event, int dry_run, *duration += timespec_to_usec(&t_end); } break;
case rtapp_delay:{struct timespec delay = usec_to_timespec(event->duration);log_debug("delay %d ", event->duration);*t_first = timespec_add(t_first, &delay);clock_nanosleep(CLOCK_MONOTONIC, TIMER_ABSTIME, t_first, NULL);}break; case rtapp_timer: { struct timespec t_period, t_now, t_wu, t_slack;diff --git a/src/rt-app_parse_config.c b/src/rt-app_parse_config.c index c59b56290bbf..f8d0f52f3ab9 100644 --- a/src/rt-app_parse_config.c +++ b/src/rt-app_parse_config.c @@ -339,7 +339,8 @@ parse_thread_event_data(char *name, struct json_object *obj, int i;
if (!strncmp(name, "run", strlen("run")) ||
!strncmp(name, "sleep", strlen("sleep"))) {
!strncmp(name, "sleep", strlen("sleep")) ||!strncmp(name, "delay", strlen("delay"))) { if (!json_object_is_type(obj, json_type_int)) goto unknown_event;@@ -350,6 +351,8 @@ parse_thread_event_data(char *name, struct json_object *obj, data->type = rtapp_sleep; else if (!strncmp(name, "runtime", strlen("runtime"))) data->type = rtapp_runtime;
else if (!strncmp(name, "delay", strlen("delay")))data->type = rtapp_delay; else data->type = rtapp_run;@@ -562,6 +565,7 @@ static char *events[] = { "sleep", "runtime", "run",
"delay", "timer", "suspend", "resume",diff --git a/src/rt-app_types.h b/src/rt-app_types.h index 0570e7b5ad3e..cb7c9242f82e 100644 --- a/src/rt-app_types.h +++ b/src/rt-app_types.h @@ -58,6 +58,7 @@ typedef enum resource_t rtapp_signal, rtapp_broadcast, rtapp_sleep,
rtapp_delay, rtapp_run, rtapp_sig_and_wait, rtapp_lock,diff --git a/src/rt-app_utils.c b/src/rt-app_utils.c index 45cf26a964e2..eeb8e7b04e91 100644 --- a/src/rt-app_utils.c +++ b/src/rt-app_utils.c @@ -215,6 +215,8 @@ string_to_resource(const char *name, resource_t *resource) *resource = rtapp_sig_and_wait; else if (strcmp(name, "sleep") == 0) *resource = rtapp_sleep;
else if (strcmp(name, "delay") == 0)*resource = rtapp_delay; else if (strcmp(name, "run") == 0) *resource = rtapp_run; else if (strcmp(name, "timer") == 0)@@ -246,6 +248,9 @@ resource_to_string(resource_t resource, char *resource_name) case rtapp_sleep: strcpy(resource_name, "sleep"); break;
case rtapp_delay:strcpy(resource_name, "delay");break; case rtapp_run: strcpy(resource_name, "run"); break;-- 2.10.0
On 14/11/16 17:08, Vincent Guittot wrote:
On 11 November 2016 at 10:17, Juri Lelli juri.lelli@arm.com wrote:
Add a new phase called 'delay' with which the initial starting time of a task can be delayed. Parameter is expressed in usec.
Could you add a description of the command in the tutorial.txt document ?
Sure, will do.
Usage is:
"phases": { "p0": { "delay": 1500000
}, ... other phases ...}
This delay seems to be more a thread's properties than a event : It should be called only once in a dedicated phase You should better parse it and set t_first in the parse_thread_data
I agree. Something like this then?
"tasks" : { "thread0" : { "instance" : 1, "loop" : -1, "delay" : 1000000, "run" : 10000, "timer" : { "ref" : "unique", "period" : 100000 } }, "thread1" : { "instance" : 1, "loop" : -1, "delay" : 500000, "run" : 10000, "timer" : { "ref" : "unique", "period" : 100000 } } },
Which is implemented by (after reverting previous patch):
--->8---
From 958e172ddfb2f942b49cd649240b69e0d356dc03 Mon Sep 17 00:00:00 2001
From: Juri Lelli juri.lelli@arm.com Date: Thu, 17 Nov 2016 11:35:13 +0000 Subject: [PATCH] rt-app: add delay thread property
Add a new thread property called 'delay' with which the initial starting time of a thread con be delayed. Parameter is expressed in usec.
Usage is:
"tasks" : { "thread0" : { ... "delay" : 1000000, ... } }
Signed-off-by: Juri Lelli juri.lelli@arm.com --- src/rt-app.c | 10 ++++++++++ src/rt-app_parse_config.c | 5 +++++ src/rt-app_types.h | 2 ++ 3 files changed, 17 insertions(+)
diff --git a/src/rt-app.c b/src/rt-app.c index 76ae11ce8f7f..9c66e9fabad9 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
On 17 November 2016 at 12:42, Juri Lelli juri.lelli@arm.com wrote:
On 14/11/16 17:08, Vincent Guittot wrote:
On 11 November 2016 at 10:17, Juri Lelli juri.lelli@arm.com wrote:
Add a new phase called 'delay' with which the initial starting time of a task can be delayed. Parameter is expressed in usec.
Could you add a description of the command in the tutorial.txt document ?
Sure, will do.
Usage is:
"phases": { "p0": { "delay": 1500000
}, ... other phases ...}
This delay seems to be more a thread's properties than a event : It should be called only once in a dedicated phase You should better parse it and set t_first in the parse_thread_data
I agree. Something like this then?
yes, your proposal below looks ok
"tasks" : { "thread0" : { "instance" : 1, "loop" : -1, "delay" : 1000000, "run" : 10000, "timer" : { "ref" : "unique", "period" : 100000 } }, "thread1" : { "instance" : 1, "loop" : -1, "delay" : 500000, "run" : 10000, "timer" : { "ref" : "unique", "period" : 100000 } } },
Which is implemented by (after reverting previous patch):
--->8--- From 958e172ddfb2f942b49cd649240b69e0d356dc03 Mon Sep 17 00:00:00 2001 From: Juri Lelli juri.lelli@arm.com Date: Thu, 17 Nov 2016 11:35:13 +0000 Subject: [PATCH] rt-app: add delay thread property
Add a new thread property called 'delay' with which the initial starting time of a thread con be delayed. Parameter is expressed in usec.
Usage is:
"tasks" : { "thread0" : { ... "delay" : 1000000, ... } }
Signed-off-by: Juri Lelli juri.lelli@arm.com
src/rt-app.c | 10 ++++++++++ src/rt-app_parse_config.c | 5 +++++ src/rt-app_types.h | 2 ++ 3 files changed, 17 insertions(+)
diff --git a/src/rt-app.c b/src/rt-app.c index 76ae11ce8f7f..9c66e9fabad9 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 100644less --- 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
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 --- src/rt-app.c | 24 +++++++++++++++++++++--- 1 file changed, 21 insertions(+), 3 deletions(-)
diff --git a/src/rt-app.c b/src/rt-app.c index 76a5c11b365c..24b4117773a1 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; @@ -174,8 +175,25 @@ int calibrate_cpu_cycles(int clock)
static inline unsigned long loadwait(unsigned long exec) { - unsigned long load_count; + unsigned long long load_count; + unsigned long secs; + int i; + + /* + * If exec is still to 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);
On 11 November 2016 at 10:17, 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
src/rt-app.c | 24 +++++++++++++++++++++--- 1 file changed, 21 insertions(+), 3 deletions(-)
diff --git a/src/rt-app.c b/src/rt-app.c index 76a5c11b365c..24b4117773a1 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;@@ -174,8 +175,25 @@ int calibrate_cpu_cycles(int clock)
static inline unsigned long loadwait(unsigned long exec) {
unsigned long load_count;
unsigned long long load_count;
Why do you need unsigned long long for load_count now that max duration is 1000000000 ns so load_count <= 1000000000
unsigned long secs;int i;/** If exec is still to big, let's run it in bursts
s/still to big/still too big/ ?
* 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 14/11/16 17:49, Vincent Guittot wrote:
On 11 November 2016 at 10:17, Juri Lelli juri.lelli@arm.com wrote:
[...]
static inline unsigned long loadwait(unsigned long exec) {
unsigned long load_count;
unsigned long long load_count;Why do you need unsigned long long for load_count now that max duration is 1000000000 ns so load_count <= 1000000000
unsigned long secs;int i;/** If exec is still to big, let's run it in burstss/still to big/still too big/ ?
Both fixed.
Thanks,
- Juri
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 24b4117773a1..cb5875b517dd 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]); @@ -330,6 +331,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;
if (rdata->res.timer.init == 0) { rdata->res.timer.init = 1; @@ -388,7 +390,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; @@ -406,7 +409,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; @@ -454,7 +458,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; @@ -591,9 +595,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); @@ -624,10 +629,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) @@ -647,6 +652,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 cb7c9242f82e..8ee951c99bf6 100644 --- a/src/rt-app_types.h +++ b/src/rt-app_types.h @@ -192,6 +192,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 eeb8e7b04e91..bba3ee2327aa 100644 --- a/src/rt-app_utils.c +++ b/src/rt-app_utils.c @@ -138,7 +138,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, @@ -147,7 +147,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"); }
This is to avoid cases where the last row can contain bogus values.
Signed-off-by: Juri Lelli juri.lelli@arm.com --- 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 cb5875b517dd..3e3d1f17ae73 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -654,7 +654,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)
Just keep log related variables on a struct to reduce the number of parameters we pass to run[_event]().
Signed-off-by: Juri Lelli juri.lelli@arm.com --- src/rt-app.c | 49 +++++++++++++++++++++++-------------------------- src/rt-app_types.h | 8 ++++++++ 2 files changed, 31 insertions(+), 26 deletions(-)
diff --git a/src/rt-app.c b/src/rt-app.c index 3e3d1f17ae73..4e7c08d7c810 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -237,9 +237,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, - unsigned long *c_period) + unsigned long *perf, rtapp_resource_t *resources, + struct timespec *t_first, log_data_t *ldata) { rtapp_resource_t *rdata = &(resources[event->res]); rtapp_resource_t *ddata = &(resources[event->dep]); @@ -293,7 +292,7 @@ static int run_event(event_data_t *event, int dry_run, *perf += loadwait(event->duration); clock_gettime(CLOCK_MONOTONIC, &t_end); t_end = timespec_sub(&t_end, &t_start); - *duration += timespec_to_usec(&t_end); + ldata->duration += timespec_to_usec(&t_end); } break; case rtapp_runtime: @@ -313,7 +312,7 @@ static int run_event(event_data_t *event, int dry_run, } while ((diff_ns / 1000) < event->duration);
t_end = timespec_sub(&t_end, &t_start); - *duration += timespec_to_usec(&t_end); + ldata->duration += timespec_to_usec(&t_end); } break; case rtapp_delay: @@ -331,7 +330,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; + ldata->c_period = event->duration;
if (rdata->res.timer.init == 0) { rdata->res.timer.init = 1; @@ -341,15 +340,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); t_slack = timespec_sub(&rdata->res.timer.t_next, &t_now); - *slack = timespec_to_usec_long(&t_slack); + ldata->slack = timespec_to_usec_long(&t_slack); if (timespec_lower(&t_now, &rdata->res.timer.t_next)) { clock_nanosleep(CLOCK_MONOTONIC, TIMER_ABSTIME, &rdata->res.timer.t_next, NULL); clock_gettime(CLOCK_MONOTONIC, &t_now); t_wu = timespec_sub(&t_now, &rdata->res.timer.t_next); - *wu_latency = timespec_to_usec(&t_wu); + ldata->wu_latency = timespec_to_usec(&t_wu); } else { clock_gettime(CLOCK_MONOTONIC, &rdata->res.timer.t_next); - *wu_latency = 0UL; + ldata->wu_latency = 0UL; } } break; @@ -386,12 +385,11 @@ static int run_event(event_data_t *event, int dry_run, return lock; }
-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, - unsigned long *c_period) +int run(int ind, + phase_data_t *pdata, + rtapp_resource_t *resources, + struct timespec *t_first, + log_data_t *ldata) { event_data_t *events = pdata->events; int nbevents = pdata->nbevents; @@ -409,8 +407,7 @@ 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, - c_period); + resources, t_first, ldata); }
return perf; @@ -455,10 +452,10 @@ void *thread_body(void *arg) { thread_data_t *data = (thread_data_t*) arg; phase_data_t *pdata; + log_data_t ldata; struct sched_param param; struct timespec t_start, t_end, t_first; unsigned long t_start_usec; - unsigned long perf, duration, wu_latency, c_period; long slack; timing_point_t *curr_timing; timing_point_t *timings; @@ -629,10 +626,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 = c_period = 0; + memset(&ldata, 0, sizeof(ldata)); clock_gettime(CLOCK_MONOTONIC, &t_start); - perf = run(data->ind, pdata, &duration, *(data->resources), - &t_first, &wu_latency, &slack, &c_period); + ldata.perf = run(data->ind, pdata, *(data->resources), + &t_first, &ldata); clock_gettime(CLOCK_MONOTONIC, &t_end);
if (timings) @@ -648,11 +645,11 @@ void *thread_body(void *arg) curr_timing->start_time = timespec_to_usec_ull(&t_start); curr_timing->end_time = timespec_to_usec_ull(&t_end); curr_timing->period = timespec_to_usec(&t_diff); - curr_timing->duration = duration; - curr_timing->perf = perf; - curr_timing->wu_latency = wu_latency; - curr_timing->slack = slack; - curr_timing->c_period = c_period; + curr_timing->duration = ldata.duration; + curr_timing->perf = ldata.perf; + curr_timing->wu_latency = ldata.wu_latency; + curr_timing->slack = ldata.slack; + curr_timing->c_period = ldata.c_period;
if (opts.logsize && !timings && continue_running) log_timing(data->log_handler, curr_timing); diff --git a/src/rt-app_types.h b/src/rt-app_types.h index 8ee951c99bf6..178a809ba5e5 100644 --- a/src/rt-app_types.h +++ b/src/rt-app_types.h @@ -161,6 +161,14 @@ typedef struct _ftrace_data_t { int marker_fd; } ftrace_data_t;
+typedef struct _log_data_t { + unsigned long perf; + unsigned long duration; + unsigned long wu_latency; + unsigned long c_period; + long slack; +} log_data_t; + typedef struct _rtapp_options_t { int lock_pages;
Move wu_lat to the end of the log, so that can be easily removed in the future if not needed anymore.
Signed-off-by: Juri Lelli juri.lelli@arm.com --- src/rt-app.c | 6 +++--- src/rt-app_utils.c | 6 +++--- 2 files changed, 6 insertions(+), 6 deletions(-)
diff --git a/src/rt-app.c b/src/rt-app.c index 4e7c08d7c810..97d071d85619 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -592,10 +592,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 %8s\n", + fprintf(data->log_handler, "%s %8s %8s %8s %15s %15s %15s %10s %8s %10s\n", "#idx", "perf", "run", "period", - "start", "end", "rel_st", "wu_lat", "slack", - "c_prd"); + "start", "end", "rel_st", "slack", + "c_prd", "wu_lat");
if (opts.ftrace) log_ftrace(ft_data.marker_fd, "[%d] starts", data->ind); diff --git a/src/rt-app_utils.c b/src/rt-app_utils.c index bba3ee2327aa..d4fd9acf5306 100644 --- a/src/rt-app_utils.c +++ b/src/rt-app_utils.c @@ -138,7 +138,7 @@ void log_timing(FILE *handler, timing_point_t *t) { fprintf(handler, - "%4d %8lu %8lu %8lu %15llu %15llu %15llu %10lu %10ld %8lu", + "%4d %8lu %8lu %8lu %15llu %15llu %15llu %10ld %8lu %10lu", t->ind, t->perf, t->duration, @@ -146,9 +146,9 @@ log_timing(FILE *handler, timing_point_t *t) t->start_time, t->end_time, t->rel_start_time, - t->wu_latency, t->slack, - t->c_period + t->c_period, + t->wu_latency ); fprintf(handler, "\n"); }
As the name is more understandable.
Signed-off-by: Juri Lelli juri.lelli@arm.com --- src/rt-app.c | 4 ++-- src/rt-app_utils.c | 2 +- 2 files changed, 3 insertions(+), 3 deletions(-)
diff --git a/src/rt-app.c b/src/rt-app.c index 97d071d85619..bf774570d97c 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -592,10 +592,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 %8s %10s\n", + fprintf(data->log_handler, "%s %8s %8s %8s %15s %15s %15s %10s %10s %10s\n", "#idx", "perf", "run", "period", "start", "end", "rel_st", "slack", - "c_prd", "wu_lat"); + "c_period", "wu_lat");
if (opts.ftrace) log_ftrace(ft_data.marker_fd, "[%d] starts", data->ind); diff --git a/src/rt-app_utils.c b/src/rt-app_utils.c index d4fd9acf5306..f24fa78735e2 100644 --- a/src/rt-app_utils.c +++ b/src/rt-app_utils.c @@ -138,7 +138,7 @@ void log_timing(FILE *handler, timing_point_t *t) { fprintf(handler, - "%4d %8lu %8lu %8lu %15llu %15llu %15llu %10ld %8lu %10lu", + "%4d %8lu %8lu %8lu %15llu %15llu %15llu %10ld %10lu %10lu", t->ind, t->perf, t->duration,
Add c_run (the run value that comes from json configuration file). This is handy for post-processing logs.
Signed-off-by: Juri Lelli juri.lelli@arm.com --- src/rt-app.c | 6 ++++-- src/rt-app_types.h | 2 ++ src/rt-app_utils.c | 3 ++- 3 files changed, 8 insertions(+), 3 deletions(-)
diff --git a/src/rt-app.c b/src/rt-app.c index bf774570d97c..d8050f2d036c 100644 --- a/src/rt-app.c +++ b/src/rt-app.c @@ -288,6 +288,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; clock_gettime(CLOCK_MONOTONIC, &t_start); *perf += loadwait(event->duration); clock_gettime(CLOCK_MONOTONIC, &t_end); @@ -592,10 +593,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 %10s\n", + fprintf(data->log_handler, "%s %8s %8s %8s %15s %15s %15s %10s %10s %10s %10s\n", "#idx", "perf", "run", "period", "start", "end", "rel_st", "slack", - "c_period", "wu_lat"); + "c_run", "c_period", "wu_lat");
if (opts.ftrace) log_ftrace(ft_data.marker_fd, "[%d] starts", data->ind); @@ -650,6 +651,7 @@ void *thread_body(void *arg) curr_timing->wu_latency = ldata.wu_latency; curr_timing->slack = ldata.slack; curr_timing->c_period = ldata.c_period; + curr_timing->c_run = ldata.c_run;
if (opts.logsize && !timings && continue_running) log_timing(data->log_handler, curr_timing); diff --git a/src/rt-app_types.h b/src/rt-app_types.h index 178a809ba5e5..9d28952f968f 100644 --- a/src/rt-app_types.h +++ b/src/rt-app_types.h @@ -165,6 +165,7 @@ typedef struct _log_data_t { unsigned long perf; unsigned long duration; unsigned long wu_latency; + unsigned long c_run; unsigned long c_period; long slack; } log_data_t; @@ -200,6 +201,7 @@ typedef struct _timing_point_t { unsigned long perf; unsigned long duration; unsigned long period; + unsigned long c_run; unsigned long c_period; unsigned long wu_latency; long slack; diff --git a/src/rt-app_utils.c b/src/rt-app_utils.c index f24fa78735e2..0791291bcd81 100644 --- a/src/rt-app_utils.c +++ b/src/rt-app_utils.c @@ -138,7 +138,7 @@ void log_timing(FILE *handler, timing_point_t *t) { fprintf(handler, - "%4d %8lu %8lu %8lu %15llu %15llu %15llu %10ld %10lu %10lu", + "%4d %8lu %8lu %8lu %15llu %15llu %15llu %10ld %10lu %10lu %10lu", t->ind, t->perf, t->duration, @@ -147,6 +147,7 @@ log_timing(FILE *handler, timing_point_t *t) t->end_time, t->rel_start_time, t->slack, + t->c_run, t->c_period, t->wu_latency );
-
Juri Lelli -
Vincent Guittot