Skip to content

S
Software for White Rabbit PTP Core
Commit d3cf39e3 authored by Grzegorz Daniluk's avatar Grzegorz Daniluk
Browse files
Options

Merge branch 'adam-max-time-monotonic' into proposed_master

parents 15242481 e4fa232e
Hide whitespace changes
Inline Side-by-side
Showing with 118 additions and 27 deletions
Kconfig
View file @ d3cf39e3
......@@ -531,6 +531,18 @@ config LATENCY_SYSLOG
bool "Report latency problems to syslog"
default y
config DEFAULT_PRINT_TASK_TIME_THRESHOLD
depends on DEVELOPER
default 0
int "Default threshold of printing task execution time"
help
If a task executes longer than a given number, its name and
an execution time will be printed to the console. Additionally,
setting this value triggers printing messages if particular task
runs longer than ever before. Setting to 0 disabled this
functionality. This value can be changed in run-time by the command
"ps max <msecs>".
# This is needed to size the pp_instance data strucuture. Instead of
# including the ppsi autoconf.h, with duplicate definitions, define it
......
configs/devel_build_test_defconfig
View file @ d3cf39e3
......@@ -65,6 +65,7 @@ CONFIG_NET_VERBOSE=y
# CONFIG_SNMP_VERBOSE is not set
CONFIG_FAKE_TEMPERATURES=y
CONFIG_LATENCY_PROBE=y
CONFIG_DEFAULT_PRINT_TASK_TIME_THRESHOLD=0
CONFIG_VLAN_ARRAY_SIZE=1
CONFIG_PRINTF_XINT=y
# CONFIG_PRINTF_FULL is not set
......
configs/gsi_defconfig
View file @ d3cf39e3
......@@ -63,6 +63,7 @@ CONFIG_PRINTF_IS_XINT=y
# CONFIG_NET_VERBOSE is not set
# CONFIG_FAKE_TEMPERATURES is not set
CONFIG_LATENCY_PROBE=y
CONFIG_DEFAULT_PRINT_TASK_TIME_THRESHOLD=0
CONFIG_VLAN_ARRAY_SIZE=1
CONFIG_PRINTF_XINT=y
# CONFIG_PRINTF_FULL is not set
......
configs/gsi_pdelay_defconfig
View file @ d3cf39e3
......@@ -63,6 +63,7 @@ CONFIG_PRINTF_IS_XINT=y
# CONFIG_NET_VERBOSE is not set
# CONFIG_FAKE_TEMPERATURES is not set
CONFIG_LATENCY_PROBE=y
CONFIG_DEFAULT_PRINT_TASK_TIME_THRESHOLD=0
CONFIG_VLAN_ARRAY_SIZE=1
CONFIG_PRINTF_XINT=y
# CONFIG_PRINTF_FULL is not set
......
configs/wrpc_sim_defconfig
View file @ d3cf39e3
......@@ -59,6 +59,7 @@ CONFIG_PRINTF_IS_XINT=y
# CONFIG_NET_VERBOSE is not set
# CONFIG_FAKE_TEMPERATURES is not set
# CONFIG_LATENCY_PROBE is not set
CONFIG_DEFAULT_PRINT_TASK_TIME_THRESHOLD=0
CONFIG_VLAN_ARRAY_SIZE=1
CONFIG_PRINTF_XINT=y
# CONFIG_PRINTF_FULL is not set
......
doc/wrpc.tex
View file @ d3cf39e3
......@@ -1523,25 +1523,47 @@ The node now has a \textit{ps} command, that shows the number of iterations
and time spent in each \textit{task}. Each task reports when it did
something (as opposed to just polling the clock or network socket and
seeing that nothing is there to do); the \textit{iterations} count shows how many
times the task did something.
\begin{lstlisting}
wrc# ps
iterations seconds.micros name
44288501 4242.816329 idle
0 0.000000 spll-bh
37 0.016549 shell+gui
8992 1.158969 ptp
4252 0.037005 uptime
1 0.001035 check-link
0 0.000000 stats
0 0.000000 net-bh
568 5.068343 temperature
times the task did something. The \textit{max\_ms} show the longest execution
time of a particular task.
\begin{lstlisting}
wrc# ps
iterations seconds.micros max_ms name
145560 29.007144 75 idle
0 0.000000 0 spll-bh
6 0.001630 1 shell+gui
642 2.540416 8 ptp
31 0.000361 1 uptime
1 0.050424 51 check-link
32 0.011172 9 diags
0 0.000000 0 stats
235 0.023562 1 net-bh
32 0.029157 2 ipv4
0 0.000000 0 arp
0 0.000000 0 snmp
6 0.054566 12 temperature
\end{lstlisting}
By using ``\texttt{ps reset}'' you can zero all counters to start a new
test run.
It is possible to configure \texttt{ps} in such way that it prints information
when any task runs longer than any run before since reset
(or \texttt{ps reset}) and when it runs longer than a specified value
in miliseconds.
For this please use command ``\texttt{ps max <msecs>}'', where
\texttt{<msecs>} is a number of miliseconds triggering printouts.
\begin{lstlisting}
wrc# ps max 10
task temperature, run for 11 ms
task temperature, run for 12 ms
task temperature, run for 11 ms
wrc# ps
[...]
New max run time for a task shell+gui, old 1, new 75
task shell+gui, run for 75 ms
\end{lstlisting}
% --------------------------------------------------------------------------
\subsubsection{Pfilter rules}
\label{Pfilter rules}
......@@ -1813,12 +1835,18 @@ tools used to build and run it, you can write to our mailing list
\code{pll stop <channel>} & stops SoftPLL for the channel \\
\code{ps} & prints the list of running tasks (processes) in the CPU. For
each task you get the number of iterations and the CPU time consumed since
boot or last reset of values \\
each task you get the number of iterations, the maximum execution time
(measured with the monotonic clock) and the CPU time consumed (using
the RT clock) since boot or last reset of values \\
\code{ps reset} & zeroes the profiling information reported by the \code{ps}
command \\
\code{ps max <msecs>} & starts printing all tasks executing longer than
a given number of miliseconds. Additionally, it triggers printing messages
if particular task runs longer than ever before. Passing ``\code{0}'' as
a parameter stops the further printouts. \\
\code{ptp <e2e|p2p>} & selects PTP delay mechanism: end-to-end or peer-to-peer.
If configured, you can set \texttt{p2p} mode. Alternatively you can use also
aliases: \texttt{delay} (instead of \texttt{e2e}) or \texttt{pdelay}
......
include/wrc-task.h
View file @ d3cf39e3
......@@ -21,6 +21,7 @@ struct wrc_task {
unsigned long nrun;
unsigned long seconds;
unsigned long nanos;
unsigned long max_run_ticks; /* in ticks */
};
/* An helper for periodic tasks, relying on a static varible */
......
shell/cmd_ps.c
View file @ d3cf39e3
......@@ -12,20 +12,29 @@
extern struct wrc_task wrc_tasks[];
extern int wrc_n_tasks;
extern uint32_t print_task_time_threshold;
static int cmd_ps(const char *args[])
{
struct wrc_task *t;
if (args[0] && !strcasecmp(args[0], "reset")) {
for_each_task(t)
t->nrun = t->seconds = t->nanos = 0;
return 0;
if (args[0]) {
if(!strcasecmp(args[0], "reset")) {
for_each_task(t)
t->nrun = t->seconds = t->nanos = t->max_run_ticks = 0;
return 0;
} else if (!strcasecmp(args[0], "max")) {
if (args[1])
print_task_time_threshold = atoi(args[1]);
pp_printf("print_task_time_threshold %d\n",
print_task_time_threshold);
return 0;
}
}
pp_printf(" iterations seconds.micros name\n");
pp_printf(" iterations seconds.micros max_ms name\n");
for_each_task(t)
pp_printf(" %9li %9li.%06li %s\n", t->nrun,
t->seconds, t->nanos/1000, t->name);
pp_printf(" %9li %9li.%06li %9ld %s\n", t->nrun,
t->seconds, t->nanos/1000, t->max_run_ticks, t->name);
return 0;
}
......
wrc_main.c
View file @ d3cf39e3
......@@ -34,6 +34,10 @@
#include "wrc_ptp.h"
#include "system_checks.h"
#ifndef CONFIG_DEFAULT_PRINT_TASK_TIME_THRESHOLD
#define CONFIG_DEFAULT_PRINT_TASK_TIME_THRESHOLD 0
#endif
int wrc_ui_mode = UI_SHELL_MODE;
int wrc_ui_refperiod = TICS_PER_SECOND; /* 1 sec */
int wrc_phase_tracking = 1;
......@@ -44,6 +48,8 @@ uint32_t cal_phase_transition = 2389;
int wrc_vlan_number = CONFIG_VLAN_NR;
static uint32_t prev_nanos_for_profile;
static uint32_t prev_ticks_for_profile;
uint32_t print_task_time_threshold = CONFIG_DEFAULT_PRINT_TASK_TIME_THRESHOLD;
static void wrc_initialize(void)
{
......@@ -104,6 +110,8 @@ static void wrc_initialize(void)
wrc_ptp_set_mode(WRC_MODE_SLAVE);
wrc_ptp_start();
shw_pps_gen_get_time(NULL, &prev_nanos_for_profile);
/* get tics */
prev_ticks_for_profile = timer_get_tics();
}
DEFINE_WRC_TASK0(idle) = {
......@@ -214,25 +222,54 @@ DEFINE_WRC_TASK(spll) = {
.job = spll_update,
};
static void task_time_normalize(struct wrc_task *t)
{
if (t->nanos > 1000 * 1000 * 1000) {
t->nanos -= 1000 * 1000 * 1000;
t->seconds++;
}
}
/* Account the time to either this task or task 0 */
static void account_task(struct wrc_task *t, int done_sth)
{
uint32_t nanos;
signed int delta;
uint32_t ticks;
signed int delta_ticks;
if (!done_sth)
t = __task_begin; /* task 0 is special */
shw_pps_gen_get_time(NULL, &nanos);
/* get monotonic number of ticks */
ticks = timer_get_tics();
delta = nanos - prev_nanos_for_profile;
if (delta < 0)
delta += 1000 * 1000 * 1000;
t->nanos += delta;
if (t->nanos > 1000 * 1000 * 1000) {
t->nanos -= 1000 * 1000 * 1000;
t->seconds++;
}
task_time_normalize(t);
prev_nanos_for_profile = nanos;
delta_ticks = ticks - prev_ticks_for_profile;
if (delta_ticks < 0)
delta_ticks += TICS_PER_SECOND;
if (t->max_run_ticks < delta_ticks) {/* update max_run_ticks */
if (print_task_time_threshold) {
/* Print only if threshold is set */
pp_printf("New max run time for a task %s, old %ld, "
"new %d\n",
t->name, t->max_run_ticks, delta_ticks);
}
t->max_run_ticks = delta_ticks;
}
if (print_task_time_threshold
&& delta_ticks > print_task_time_threshold)
pp_printf("task %s, run for %d ms\n", t->name, delta_ticks);
prev_ticks_for_profile = ticks;
}
/* Run a task with profiling */
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment