11:39 p.m.
Sometimes kernel image is generated without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO.
Where relevant commit id is f6db83479932 ("sched/stat: Simplify the sched_info
accounting")
- CONFIG_SCHED_INFO: KERNEL_VERSION >= LINUX(4,2,0)
- CONFIG_SCHEDSTATS: KERNEL_VERSION < LINUX(4,2,0)
Running crash-utility with above kernel image,
"ps -l" option cannot display all processes sorted with most recently-run
process.
Also "ps -m" option cannot display all processes with timestamp.
crash> ps -l or crash> ps -m
ps: last-run timestamps do not exist in this kernel
Usage: ps [-k|-u|-G] [-s]
[-p|-c|-t|-[l|m][-C cpu]|-a|-g|-r|-S]
[pid | task | command] ...
Enter "help ps" for details.
This is because output of "ps -l|-m" depends on
task_struct.sched_info.last_arrival.
Without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO, 'sched_info' field is not
included
in task_struct.
So we make "ps -l|-m" option to access 'exec_start' field of
sched_entity
where 'exec_start' is task_struct.se.exec_start.
With this patch, "ps -l|-m" option works well without CONFIG_SCHEDSTATS or
CONFIG_SCHED_INFO.
Signed-off-by: Austin Kim <austindh.kim(a)gmail.com>
---
defs.h | 2 ++
symbols.c | 2 ++
task.c | 20 ++++++++++++++++----
3 files changed, 20 insertions(+), 4 deletions(-)
diff --git a/defs.h b/defs.h
index bf2c59b..5dda176 100644
--- a/defs.h
+++ b/defs.h
@@ -2168,6 +2168,8 @@ struct offset_table { /* stash of commonly-used
offsets */
long sbitmap_queue_min_shallow_depth;
long sbq_wait_state_wait_cnt;
long sbq_wait_state_wait;
+ long task_struct_sched_entity;
+ long se_exec_start;
};
struct size_table { /* stash of commonly-used sizes */
diff --git a/symbols.c b/symbols.c
index ba5e274..e5abe87 100644
--- a/symbols.c
+++ b/symbols.c
@@ -8892,6 +8892,8 @@ dump_offset_table(char *spec, ulong makestruct)
OFFSET(sched_rt_entity_run_list));
fprintf(fp, " sched_info_last_arrival: %ld\n",
OFFSET(sched_info_last_arrival));
+ fprintf(fp, " se_exec_start: %ld\n",
+ OFFSET(se_exec_start));
fprintf(fp, " task_struct_thread_info: %ld\n",
OFFSET(task_struct_thread_info));
fprintf(fp, " task_struct_stack: %ld\n",
diff --git a/task.c b/task.c
index 864c838..55e2312 100644
--- a/task.c
+++ b/task.c
@@ -334,9 +334,15 @@ task_init(void)
if (VALID_MEMBER(task_struct_sched_info))
MEMBER_OFFSET_INIT(sched_info_last_arrival,
"sched_info", "last_arrival");
+ MEMBER_OFFSET_INIT(task_struct_sched_entity, "task_struct", "se");
+ if (VALID_MEMBER(task_struct_sched_entity)) {
+ STRUCT_SIZE_INIT(sched_entity, "sched_entity");
+ MEMBER_OFFSET_INIT(se_exec_start, "sched_entity", "exec_start");
+ }
if (VALID_MEMBER(task_struct_last_run) ||
VALID_MEMBER(task_struct_timestamp) ||
- VALID_MEMBER(sched_info_last_arrival)) {
+ VALID_MEMBER(sched_info_last_arrival) ||
+ VALID_MEMBER(se_exec_start)) {
char buf[BUFSIZE];
strcpy(buf, "alias last ps -l");
alias_init(buf);
@@ -3559,7 +3565,8 @@ cmd_ps(void)
case 'm':
if (INVALID_MEMBER(task_struct_last_run) &&
INVALID_MEMBER(task_struct_timestamp) &&
- INVALID_MEMBER(sched_info_last_arrival)) {
+ INVALID_MEMBER(sched_info_last_arrival) &&
+ INVALID_MEMBER(se_exec_start)) {
error(INFO,
"last-run timestamps do not exist in this
kernel\n");
argerrs++;
@@ -3574,7 +3581,8 @@ cmd_ps(void)
case 'l':
if (INVALID_MEMBER(task_struct_last_run) &&
INVALID_MEMBER(task_struct_timestamp) &&
- INVALID_MEMBER(sched_info_last_arrival)) {
+ INVALID_MEMBER(sched_info_last_arrival) &&
+ INVALID_MEMBER(se_exec_start)) {
error(INFO,
"last-run timestamps do not exist in this
kernel\n");
argerrs++;
@@ -6020,7 +6028,11 @@ task_last_run(ulong task)
timestamp = tt->last_task_read ? ULONGLONG(tt->task_struct +
OFFSET(task_struct_sched_info) +
OFFSET(sched_info_last_arrival)) : 0;
-
+ else if (VALID_MEMBER(se_exec_start))
+ timestamp = tt->last_task_read ? ULONGLONG(tt->task_struct +
+ OFFSET(task_struct_sched_entity) +
+ OFFSET(se_exec_start)) : 0;
+
return timestamp;
}
--
2.20.1
1:42 a.m.
Hi Austin,
thank you for the patch.
-----Original Message-----
Sometimes kernel image is generated without CONFIG_SCHEDSTATS or
CONFIG_SCHED_INFO.
Where relevant commit id is f6db83479932 ("sched/stat: Simplify the sched_info
accounting")
- CONFIG_SCHED_INFO: KERNEL_VERSION >= LINUX(4,2,0)
- CONFIG_SCHEDSTATS: KERNEL_VERSION < LINUX(4,2,0)
Running crash-utility with above kernel image,
"ps -l" option cannot display all processes sorted with most recently-run
process.
Also "ps -m" option cannot display all processes with timestamp.
crash> ps -l or crash> ps -m
ps: last-run timestamps do not exist in this kernel
Usage: ps [-k|-u|-G] [-s]
[-p|-c|-t|-[l|m][-C cpu]|-a|-g|-r|-S]
[pid | task | command] ...
Enter "help ps" for details.
This is because output of "ps -l|-m" depends on
task_struct.sched_info.last_arrival.
Without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO, 'sched_info' field is not
included
in task_struct.
So we make "ps -l|-m" option to access 'exec_start' field of
sched_entity
where 'exec_start' is task_struct.se.exec_start.
Could you describe what the exec_start means? When is it updated?
Checking a vmcore on hand, those values are different each other.
crash> task | grep -e exec_start -e last_arrival
exec_start = 737120183773,
last_arrival = 737112829272,
crash> task 1 | grep -e exec_start -e last_arrival
exec_start = 736519632741,
last_arrival = 736515663193,
The current last_arrival looks to be updated only by this path and
I think it's the time when a task gets a CPU:
context_switch
prepare_task_switch
sched_info_switch
sched_info_arrive
So if the meaning of the exec_start is different from last_arrival,
it would be better to have a description about it in the help text.
With this patch, "ps -l|-m" option works well without CONFIG_SCHEDSTATS or
CONFIG_SCHED_INFO.
Signed-off-by: Austin Kim <austindh.kim(a)gmail.com>
---
defs.h | 2 ++
symbols.c | 2 ++
task.c | 20 ++++++++++++++++----
3 files changed, 20 insertions(+), 4 deletions(-)
diff --git a/defs.h b/defs.h
index bf2c59b..5dda176 100644
--- a/defs.h
+++ b/defs.h
@@ -2168,6 +2168,8 @@ struct offset_table { /* stash of commonly-used
offsets */
long sbitmap_queue_min_shallow_depth;
long sbq_wait_state_wait_cnt;
long sbq_wait_state_wait;
+ long task_struct_sched_entity;
+ long se_exec_start;
Normally names in this table are "struct_name_member_name", so
these should be "task_struct_se" and "sched_entity_exec_start"
respectively.
And "task_struct_se" already exists, so please fix those.
long cfs_rq_tasks_timeline;
long task_struct_se;
long sched_entity_run_node;
};
struct size_table { /* stash of commonly-used sizes */
diff --git a/symbols.c b/symbols.c
index ba5e274..e5abe87 100644
--- a/symbols.c
+++ b/symbols.c
@@ -8892,6 +8892,8 @@ dump_offset_table(char *spec, ulong makestruct)
OFFSET(sched_rt_entity_run_list));
fprintf(fp, " sched_info_last_arrival: %ld\n",
OFFSET(sched_info_last_arrival));
+ fprintf(fp, " se_exec_start: %ld\n",
+ OFFSET(se_exec_start));
There are already some sched_entity members, please move this here.
fprintf(fp, " task_struct_se: %ld\n",
OFFSET(task_struct_se));
fprintf(fp, " sched_entity_run_node: %ld\n",
OFFSET(sched_entity_run_node));
fprintf(fp, " sched_entity_cfs_rq: %ld\n",
OFFSET(sched_entity_cfs_rq));
fprintf(fp, " sched_entity_my_q: %ld\n",
OFFSET(sched_entity_my_q));
fprintf(fp, " sched_entity_on_rq: %ld\n",
OFFSET(sched_entity_on_rq));
Thanks,
Kazu
fprintf(fp, " task_struct_thread_info:
%ld\n",
OFFSET(task_struct_thread_info));
fprintf(fp, " task_struct_stack: %ld\n",
diff --git a/task.c b/task.c
index 864c838..55e2312 100644
--- a/task.c
+++ b/task.c
@@ -334,9 +334,15 @@ task_init(void)
if (VALID_MEMBER(task_struct_sched_info))
MEMBER_OFFSET_INIT(sched_info_last_arrival,
"sched_info", "last_arrival");
+ MEMBER_OFFSET_INIT(task_struct_sched_entity, "task_struct", "se");
+ if (VALID_MEMBER(task_struct_sched_entity)) {
+ STRUCT_SIZE_INIT(sched_entity, "sched_entity");
+ MEMBER_OFFSET_INIT(se_exec_start, "sched_entity", "exec_start");
+ }
if (VALID_MEMBER(task_struct_last_run) ||
VALID_MEMBER(task_struct_timestamp) ||
- VALID_MEMBER(sched_info_last_arrival)) {
+ VALID_MEMBER(sched_info_last_arrival) ||
+ VALID_MEMBER(se_exec_start)) {
char buf[BUFSIZE];
strcpy(buf, "alias last ps -l");
alias_init(buf);
@@ -3559,7 +3565,8 @@ cmd_ps(void)
case 'm':
if (INVALID_MEMBER(task_struct_last_run) &&
INVALID_MEMBER(task_struct_timestamp) &&
- INVALID_MEMBER(sched_info_last_arrival)) {
+ INVALID_MEMBER(sched_info_last_arrival) &&
+ INVALID_MEMBER(se_exec_start)) {
error(INFO,
"last-run timestamps do not exist in this
kernel\n");
argerrs++;
@@ -3574,7 +3581,8 @@ cmd_ps(void)
case 'l':
if (INVALID_MEMBER(task_struct_last_run) &&
INVALID_MEMBER(task_struct_timestamp) &&
- INVALID_MEMBER(sched_info_last_arrival)) {
+ INVALID_MEMBER(sched_info_last_arrival) &&
+ INVALID_MEMBER(se_exec_start)) {
error(INFO,
"last-run timestamps do not exist in this
kernel\n");
argerrs++;
@@ -6020,7 +6028,11 @@ task_last_run(ulong task)
timestamp = tt->last_task_read ? ULONGLONG(tt->task_struct +
OFFSET(task_struct_sched_info) +
OFFSET(sched_info_last_arrival)) : 0;
-
+ else if (VALID_MEMBER(se_exec_start))
+ timestamp = tt->last_task_read ? ULONGLONG(tt->task_struct +
+ OFFSET(task_struct_sched_entity) +
+ OFFSET(se_exec_start)) : 0;
+
return timestamp;
}
--
2.20.1
6:49 a.m.
Hello, Kazu
2022년 3월 1일 (화) 오후 4:42, HAGIO KAZUHITO(萩尾 一仁) <k-hagio-ab(a)nec.xn--com>-4f21ay07k 작성:
Hi Austin,
thank you for the patch.
-----Original Message-----
> Sometimes kernel image is generated without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO.
> Where relevant commit id is f6db83479932 ("sched/stat: Simplify the sched_info
accounting")
>
> - CONFIG_SCHED_INFO: KERNEL_VERSION >= LINUX(4,2,0)
> - CONFIG_SCHEDSTATS: KERNEL_VERSION < LINUX(4,2,0)
>
> Running crash-utility with above kernel image,
> "ps -l" option cannot display all processes sorted with most recently-run
process.
> Also "ps -m" option cannot display all processes with timestamp.
>
> crash> ps -l or crash> ps -m
> ps: last-run timestamps do not exist in this kernel
> Usage: ps [-k|-u|-G] [-s]
> [-p|-c|-t|-[l|m][-C cpu]|-a|-g|-r|-S]
> [pid | task | command] ...
> Enter "help ps" for details.
>
> This is because output of "ps -l|-m" depends on
task_struct.sched_info.last_arrival.
>
> Without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO, 'sched_info' field is not
included
> in task_struct.
>
> So we make "ps -l|-m" option to access 'exec_start' field of
sched_entity
> where 'exec_start' is task_struct.se.exec_start.
Could you describe what the exec_start means? When is it updated?
The 'task_struct.se.exec_start' contains the most recently-executed
timestamp when
process is running in the below cases;
- enqueued to runqueue
- dequeued from ruqueue
- scheduler tick is invoked
- etc
So I guess 'task_struct.se.exec_start' could be one of statistics
which indicates
the most recently run timestamp of process activity.
From CFS scheduler's point of view,
'task_struct.se.exec_start' is
updated within update_curr()
where its call path is various as below.
- enqueue_task_fair, -dequeue_task_fair, task_tick_fair,
check_preempt_wakeup, ...
Checking a vmcore on hand, those values are different each other.
crash> task | grep -e exec_start -e last_arrival
exec_start = 737120183773,
last_arrival = 737112829272,
crash> task 1 | grep -e exec_start -e last_arrival
exec_start = 736519632741,
last_arrival = 736515663193,
The current last_arrival looks to be updated only by this path and
I think it's the time when a task gets a CPU:
context_switch
prepare_task_switch
sched_info_switch
sched_info_arrive
So if the meaning of the exec_start is different from last_arrival,
it would be better to have a description about it in the help text.
With the next v3 patch, description about exec_start will be included
in help text and
commit message. Thanks for feedback.
>
> With this patch, "ps -l|-m" option works well without CONFIG_SCHEDSTATS
or
> CONFIG_SCHED_INFO.
>
> Signed-off-by: Austin Kim <austindh.kim(a)gmail.com>
> ---
> defs.h | 2 ++
> symbols.c | 2 ++
> task.c | 20 ++++++++++++++++----
> 3 files changed, 20 insertions(+), 4 deletions(-)
>
> diff --git a/defs.h b/defs.h
> index bf2c59b..5dda176 100644
> --- a/defs.h
> +++ b/defs.h
> @@ -2168,6 +2168,8 @@ struct offset_table { /* stash of
commonly-used offsets */
> long sbitmap_queue_min_shallow_depth;
> long sbq_wait_state_wait_cnt;
> long sbq_wait_state_wait;
> + long task_struct_sched_entity;
> + long se_exec_start;
Normally names in this table are "struct_name_member_name", so
these should be "task_struct_se" and "sched_entity_exec_start"
respectively.
And "task_struct_se" already exists, so please fix those.
Sure, let me resend the v3 patch after renaming member.
long cfs_rq_tasks_timeline;
long task_struct_se;
long sched_entity_run_node;
> };
>
> struct size_table { /* stash of commonly-used sizes */
> diff --git a/symbols.c b/symbols.c
> index ba5e274..e5abe87 100644
> --- a/symbols.c
> +++ b/symbols.c
> @@ -8892,6 +8892,8 @@ dump_offset_table(char *spec, ulong makestruct)
> OFFSET(sched_rt_entity_run_list));
> fprintf(fp, " sched_info_last_arrival: %ld\n",
> OFFSET(sched_info_last_arrival));
> + fprintf(fp, " se_exec_start: %ld\n",
> + OFFSET(se_exec_start));
There are already some sched_entity members, please move this here.
Thanks for feedback.
it will be moved as you recommended in the next v3 patch.
fprintf(fp, " task_struct_se:
%ld\n",
OFFSET(task_struct_se));
fprintf(fp, " sched_entity_run_node: %ld\n",
OFFSET(sched_entity_run_node));
fprintf(fp, " sched_entity_cfs_rq: %ld\n",
OFFSET(sched_entity_cfs_rq));
fprintf(fp, " sched_entity_my_q: %ld\n",
OFFSET(sched_entity_my_q));
fprintf(fp, " sched_entity_on_rq: %ld\n",
OFFSET(sched_entity_on_rq));
Thanks,
Kazu
> fprintf(fp, " task_struct_thread_info: %ld\n",
> OFFSET(task_struct_thread_info));
> fprintf(fp, " task_struct_stack: %ld\n",
> diff --git a/task.c b/task.c
> index 864c838..55e2312 100644
> --- a/task.c
> +++ b/task.c
> @@ -334,9 +334,15 @@ task_init(void)
> if (VALID_MEMBER(task_struct_sched_info))
> MEMBER_OFFSET_INIT(sched_info_last_arrival,
> "sched_info", "last_arrival");
> + MEMBER_OFFSET_INIT(task_struct_sched_entity, "task_struct",
"se");
> + if (VALID_MEMBER(task_struct_sched_entity)) {
> + STRUCT_SIZE_INIT(sched_entity, "sched_entity");
> + MEMBER_OFFSET_INIT(se_exec_start, "sched_entity",
"exec_start");
> + }
> if (VALID_MEMBER(task_struct_last_run) ||
> VALID_MEMBER(task_struct_timestamp) ||
> - VALID_MEMBER(sched_info_last_arrival)) {
> + VALID_MEMBER(sched_info_last_arrival) ||
> + VALID_MEMBER(se_exec_start)) {
> char buf[BUFSIZE];
> strcpy(buf, "alias last ps -l");
> alias_init(buf);
> @@ -3559,7 +3565,8 @@ cmd_ps(void)
> case 'm':
> if (INVALID_MEMBER(task_struct_last_run) &&
> INVALID_MEMBER(task_struct_timestamp) &&
> - INVALID_MEMBER(sched_info_last_arrival)) {
> + INVALID_MEMBER(sched_info_last_arrival) &&
> + INVALID_MEMBER(se_exec_start)) {
> error(INFO,
> "last-run timestamps do not exist in this
kernel\n");
> argerrs++;
> @@ -3574,7 +3581,8 @@ cmd_ps(void)
> case 'l':
> if (INVALID_MEMBER(task_struct_last_run) &&
> INVALID_MEMBER(task_struct_timestamp) &&
> - INVALID_MEMBER(sched_info_last_arrival)) {
> + INVALID_MEMBER(sched_info_last_arrival) &&
> + INVALID_MEMBER(se_exec_start)) {
> error(INFO,
> "last-run timestamps do not exist in this
kernel\n");
> argerrs++;
> @@ -6020,7 +6028,11 @@ task_last_run(ulong task)
> timestamp = tt->last_task_read ? ULONGLONG(tt->task_struct +
> OFFSET(task_struct_sched_info) +
> OFFSET(sched_info_last_arrival)) : 0;
> -
> + else if (VALID_MEMBER(se_exec_start))
> + timestamp = tt->last_task_read ?
ULONGLONG(tt->task_struct +
> + OFFSET(task_struct_sched_entity) +
> + OFFSET(se_exec_start)) : 0;
> +
> return timestamp;
> }
>
> --
> 2.20.1
1:50 a.m.
Hi Austin,
-----Original Message-----
> > This is because output of "ps -l|-m" depends on
task_struct.sched_info.last_arrival.
> >
> > Without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO, 'sched_info' field is
not included
> > in task_struct.
> >
> > So we make "ps -l|-m" option to access 'exec_start' field of
sched_entity
> > where 'exec_start' is task_struct.se.exec_start.
>
> Could you describe what the exec_start means? When is it updated?
>
The 'task_struct.se.exec_start' contains the most recently-executed
timestamp when
process is running in the below cases;
- enqueued to runqueue
- dequeued from ruqueue
- scheduler tick is invoked
- etc
So I guess 'task_struct.se.exec_start' could be one of statistics
which indicates
the most recently run timestamp of process activity.
From CFS scheduler's point of view, 'task_struct.se.exec_start' is
updated within update_curr()
where its call path is various as below.
- enqueue_task_fair, -dequeue_task_fair, task_tick_fair,
check_preempt_wakeup, ...
Thank you for looking into this.
As for when the se.exec_start is updated, I think you are right.
(with my understanding, probably it's the last time or tick when a task
is in a runqueue regardless of getting a CPU.)
But I found a problem, is that the se.exec_start is from rq->clock_task,
not from rq->clock like last_arrival. The rq->clock_task may not contain
irq/steal time, please see update_rq_clock_task().
This causes the following issues with a vmcore generated on a machine,
which had run for a while (273 days):
crash> ps -m | head
[ 0 00:59:36.582] [RU] PID: 4023608 TASK: ffff916f7c6b1840 CPU: 15 COMMAND:
"makedumpfile"
^^^^^^^^^(1)
[ 0 00:59:37.831] [ID] PID: 413 TASK: ffff916f772d3080 CPU: 15 COMMAND:
"kworker/15:1H"
[ 0 00:59:39.765] [IN] PID: 3929504 TASK: ffff916f5f0748c0 CPU: 15 COMMAND:
"respawn_actlog"
[ 0 00:59:40.650] [IN] PID: 1974 TASK: ffff91647dc53080 CPU: 15 COMMAND: "CPU
2/KVM"
[ 0 00:59:41.925] [IN] PID: 1297 TASK: ffff916f63c46100 CPU: 15 COMMAND:
"NetworkManager"
[ 0 00:59:42.944] [ID] PID: 3763057 TASK: ffff9160c4519840 CPU: 15 COMMAND:
"kworker/15:0"
[ 0 00:59:42.944] [IN] PID: 101 TASK: ffff916040c91840 CPU: 15 COMMAND:
"migration/15"
[ 0 00:59:43.078] [IN] PID: 100 TASK: ffff916040c5b080 CPU: 15 COMMAND:
"watchdog/15"
[ 0 00:59:47.533] [IN] PID: 1292 TASK: ffff916f63c43080 CPU: 15 COMMAND:
"lsmd"
[ 0 00:59:49.089] [IN] PID: 113105 TASK: ffff9160412248c0 CPU: 15 COMMAND:
"kvm-nx-lpage-re"
^^^^^^^(2)
(1) large difference from zero
(2) large differences among CPUs (probably due to the differences of irq time)
(1) might be solved with rq->clock_task, but (2) will be misleading and confusing.
So currently I'm thinking that the "ps -l|-m" options should not use the
se.exec_start.
What do you think?
Thanks,
Kazu
7:19 a.m.
Hello, Kazu
2022년 3월 3일 (목) 오후 4:50, HAGIO KAZUHITO(萩尾 一仁) <k-hagio-ab(a)nec.xn--com>-4f21ay07k 작성:
Hi Austin,
-----Original Message-----
> > > This is because output of "ps -l|-m" depends on
task_struct.sched_info.last_arrival.
> > >
> > > Without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO, 'sched_info' field
is not included
> > > in task_struct.
> > >
> > > So we make "ps -l|-m" option to access 'exec_start'
field of sched_entity
> > > where 'exec_start' is task_struct.se.exec_start.
> >
> > Could you describe what the exec_start means? When is it updated?
> >
>
> The 'task_struct.se.exec_start' contains the most recently-executed
> timestamp when
> process is running in the below cases;
>
> - enqueued to runqueue
> - dequeued from ruqueue
> - scheduler tick is invoked
> - etc
>
> So I guess 'task_struct.se.exec_start' could be one of statistics
> which indicates
> the most recently run timestamp of process activity.
>
> From CFS scheduler's point of view, 'task_struct.se.exec_start' is
> updated within update_curr()
> where its call path is various as below.
>
> - enqueue_task_fair, -dequeue_task_fair, task_tick_fair,
> check_preempt_wakeup, ...
Thank you for looking into this.
As for when the se.exec_start is updated, I think you are right.
(with my understanding, probably it's the last time or tick when a task
is in a runqueue regardless of getting a CPU.)
But I found a problem, is that the se.exec_start is from rq->clock_task,
not from rq->clock like last_arrival. The rq->clock_task may not contain
irq/steal time, please see update_rq_clock_task().
I am understood after looking at below code.
static void sched_info_arrive(struct rq *rq, struct task_struct *t)
{
...
now = rq_clock(rq); //<<--
...
t->sched_info.last_arrival = now;
}
static void update_curr(struct cfs_rq *cfs_rq)
{
u64 now = rq_clock_task(rq_of(cfs_rq)); //<<--
...
curr->exec_start = now;
...
}
This causes the following issues with a vmcore generated on a
machine,
which had run for a while (273 days):
Let me ask a question at this point.
The vmcore was generated from machine which has been running 273 days.
I wonder the kernel image of machine(running 273 days) is without
CONFIG_SCHEDSTATS/CONFIG_SCHED_INFO.
If output is based on vmcore without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO,
you can ignore above question.
I would like to remind that as commit description said, the patch is
**only** valid
without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO.
When kernel image is with CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO and then
"ps -l|-m" command is used, task_last_run() is called from its subroutines.
ulonglong
task_last_run(ulong task)
{
ulong last_run;
...
else if (VALID_MEMBER(sched_info_last_arrival)) // With
CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO
timestamp = tt->last_task_read ? ULONGLONG(tt->task_struct +
OFFSET(task_struct_sched_info) +
OFFSET(sched_info_last_arrival)) : 0;
+ else if (VALID_MEMBER(sched_entity_exec_start)) // Without
CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO
+ timestamp = tt->last_task_read ? ULONGLONG(tt->task_struct +
+ OFFSET(task_struct_se) +
+ OFFSET(sched_entity_exec_start)) : 0;
return timestamp;
}
With CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO enabled,
the statement under 'VALID_MEMBER(sched_entity_exec_start)' is not called.
crash> ps -m | head
[ 0 00:59:36.582] [RU] PID: 4023608 TASK: ffff916f7c6b1840 CPU: 15 COMMAND:
"makedumpfile"
^^^^^^^^^(1)
[ 0 00:59:37.831] [ID] PID: 413 TASK: ffff916f772d3080 CPU: 15 COMMAND:
"kworker/15:1H"
[ 0 00:59:39.765] [IN] PID: 3929504 TASK: ffff916f5f0748c0 CPU: 15 COMMAND:
"respawn_actlog"
[ 0 00:59:40.650] [IN] PID: 1974 TASK: ffff91647dc53080 CPU: 15 COMMAND:
"CPU 2/KVM"
[ 0 00:59:41.925] [IN] PID: 1297 TASK: ffff916f63c46100 CPU: 15 COMMAND:
"NetworkManager"
[ 0 00:59:42.944] [ID] PID: 3763057 TASK: ffff9160c4519840 CPU: 15 COMMAND:
"kworker/15:0"
[ 0 00:59:42.944] [IN] PID: 101 TASK: ffff916040c91840 CPU: 15 COMMAND:
"migration/15"
[ 0 00:59:43.078] [IN] PID: 100 TASK: ffff916040c5b080 CPU: 15 COMMAND:
"watchdog/15"
[ 0 00:59:47.533] [IN] PID: 1292 TASK: ffff916f63c43080 CPU: 15 COMMAND:
"lsmd"
[ 0 00:59:49.089] [IN] PID: 113105 TASK: ffff9160412248c0 CPU: 15 COMMAND:
"kvm-nx-lpage-re"
^^^^^^^(2)
(1) large difference from zero
(2) large differences among CPUs (probably due to the differences of irq time)
(1) might be solved with rq->clock_task, but (2) will be misleading and confusing.
So currently I'm thinking that the "ps -l|-m" options should not use the
se.exec_start.
What do you think?
Agreed. (As you indicated) Since rq->clock cannot hold accurate
timestamp we can rely on,
"ps -l|-m" options should not access the se.exec_start in case of kernel image
without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO.
Thanks for your code review.
If there is something to improve, let me propose a patch again.
BR,
Austin Kim
Thanks,
Kazu
6:22 p.m.
-----Original Message-----
> But I found a problem, is that the se.exec_start is from
rq->clock_task,
> not from rq->clock like last_arrival. The rq->clock_task may not contain
> irq/steal time, please see update_rq_clock_task().
>
I am understood after looking at below code.
static void sched_info_arrive(struct rq *rq, struct task_struct *t)
{
...
now = rq_clock(rq); //<<--
...
t->sched_info.last_arrival = now;
}
static void update_curr(struct cfs_rq *cfs_rq)
{
u64 now = rq_clock_task(rq_of(cfs_rq)); //<<--
...
curr->exec_start = now;
...
}
Yes, right.
> This causes the following issues with a vmcore generated on a
machine,
> which had run for a while (273 days):
>
Let me ask a question at this point.
The vmcore was generated from machine which has been running 273 days.
I wonder the kernel image of machine(running 273 days) is without
CONFIG_SCHEDSTATS/CONFIG_SCHED_INFO.
If output is based on vmcore without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO,
you can ignore above question.
oh, I should have explain it.
I have no vmcore without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO on hand, so
I dropped the code using last_arrival to simulate it and use the se.exec_start.
--- a/task.c
+++ b/task.c
@@ -6024,10 +6024,6 @@ task_last_run(ulong task)
} else if (VALID_MEMBER(task_struct_timestamp))
timestamp = tt->last_task_read ? ULONGLONG(tt->task_struct +
OFFSET(task_struct_timestamp)) : 0;
- else if (VALID_MEMBER(sched_info_last_arrival))
- timestamp = tt->last_task_read ? ULONGLONG(tt->task_struct +
- OFFSET(task_struct_sched_info) +
- OFFSET(sched_info_last_arrival)) : 0;
else if (VALID_MEMBER(sched_entity_exec_start))
timestamp = tt->last_task_read ? ULONGLONG(tt->task_struct
+
OFFSET(task_struct_se) +
crash> help -o | grep -e task_struct_last_run -e task_struct_timestamp -e
sched_info_last_arrival -e sched_entity_exec_start
task_struct_last_run: -1
task_struct_timestamp: -1
sched_info_last_arrival: 16
sched_entity_exec_start: 72
crash> ps -l
[23601334315087174] [RU] PID: 4023608 TASK: ffff916f7c6b1840 CPU: 15 COMMAND:
"makedumpfile"
...
crash> task 4023608 | grep exec_start
exec_start = 23601334315087174,
I would like to remind that as commit description said, the patch is
**only** valid
without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO.
When kernel image is with CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO and then
"ps -l|-m" command is used, task_last_run() is called from its subroutines.
ulonglong
task_last_run(ulong task)
{
ulong last_run;
...
else if (VALID_MEMBER(sched_info_last_arrival)) // With
CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO
timestamp = tt->last_task_read ? ULONGLONG(tt->task_struct +
OFFSET(task_struct_sched_info) +
OFFSET(sched_info_last_arrival)) : 0;
+ else if (VALID_MEMBER(sched_entity_exec_start)) // Without
CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO
+ timestamp = tt->last_task_read ? ULONGLONG(tt->task_struct +
+ OFFSET(task_struct_se) +
+ OFFSET(sched_entity_exec_start)) : 0;
return timestamp;
}
With CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO enabled,
the statement under 'VALID_MEMBER(sched_entity_exec_start)' is not called.
> crash> ps -m | head
> [ 0 00:59:36.582] [RU] PID: 4023608 TASK: ffff916f7c6b1840 CPU: 15 COMMAND:
"makedumpfile"
> ^^^^^^^^^(1)
> [ 0 00:59:37.831] [ID] PID: 413 TASK: ffff916f772d3080 CPU: 15 COMMAND:
"kworker/15:1H"
> [ 0 00:59:39.765] [IN] PID: 3929504 TASK: ffff916f5f0748c0 CPU: 15 COMMAND:
"respawn_actlog"
> [ 0 00:59:40.650] [IN] PID: 1974 TASK: ffff91647dc53080 CPU: 15 COMMAND:
"CPU 2/KVM"
> [ 0 00:59:41.925] [IN] PID: 1297 TASK: ffff916f63c46100 CPU: 15 COMMAND:
"NetworkManager"
> [ 0 00:59:42.944] [ID] PID: 3763057 TASK: ffff9160c4519840 CPU: 15 COMMAND:
"kworker/15:0"
> [ 0 00:59:42.944] [IN] PID: 101 TASK: ffff916040c91840 CPU: 15 COMMAND:
"migration/15"
> [ 0 00:59:43.078] [IN] PID: 100 TASK: ffff916040c5b080 CPU: 15 COMMAND:
"watchdog/15"
> [ 0 00:59:47.533] [IN] PID: 1292 TASK: ffff916f63c43080 CPU: 15 COMMAND:
"lsmd"
> [ 0 00:59:49.089] [IN] PID: 113105 TASK: ffff9160412248c0 CPU: 15 COMMAND:
"kvm-nx-lpage-re"
> ^^^^^^^(2)
> (1) large difference from zero
> (2) large differences among CPUs (probably due to the differences of irq time)
>
> (1) might be solved with rq->clock_task, but (2) will be misleading and
confusing.
> So currently I'm thinking that the "ps -l|-m" options should not use
the se.exec_start.
> What do you think?
>
Agreed. (As you indicated) Since rq->clock cannot hold accurate
timestamp we can rely on,
"ps -l|-m" options should not access the se.exec_start in case of kernel image
without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO.
Thanks for your code review.
If there is something to improve, let me propose a patch again.
Sure.
I think that the se.exec_start itself may be somewhat useful, especially for
dumpfiles without CONFIG_SCHED{STATS,_INFO}, but not suitable for the current
"ps -l|-m" behavior. There may be another way to make good use of it.
Thanks,
Kazu
8:16 p.m.
Hello, Kazu
2022년 3월 4일 (금) 오전 9:22, HAGIO KAZUHITO(萩尾 一仁) <k-hagio-ab(a)nec.xn--com>-4f21ay07k 작성:
-----Original Message-----
> > But I found a problem, is that the se.exec_start is from rq->clock_task,
> > not from rq->clock like last_arrival. The rq->clock_task may not
contain
> > irq/steal time, please see update_rq_clock_task().
> >
>
> I am understood after looking at below code.
>
> static void sched_info_arrive(struct rq *rq, struct task_struct *t)
> {
> ...
> now = rq_clock(rq); //<<--
> ...
> t->sched_info.last_arrival = now;
> }
> static void update_curr(struct cfs_rq *cfs_rq)
> {
> u64 now = rq_clock_task(rq_of(cfs_rq)); //<<--
> ...
> curr->exec_start = now;
> ...
> }
Yes, right.
> > This causes the following issues with a vmcore generated on a machine,
> > which had run for a while (273 days):
> >
>
> Let me ask a question at this point.
> The vmcore was generated from machine which has been running 273 days.
>
> I wonder the kernel image of machine(running 273 days) is without
> CONFIG_SCHEDSTATS/CONFIG_SCHED_INFO.
> If output is based on vmcore without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO,
> you can ignore above question.
oh, I should have explain it.
I have no vmcore without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO on hand, so
I dropped the code using last_arrival to simulate it and use the se.exec_start.
--- a/task.c
+++ b/task.c
@@ -6024,10 +6024,6 @@ task_last_run(ulong task)
} else if (VALID_MEMBER(task_struct_timestamp))
timestamp = tt->last_task_read ? ULONGLONG(tt->task_struct +
OFFSET(task_struct_timestamp)) : 0;
- else if (VALID_MEMBER(sched_info_last_arrival))
- timestamp = tt->last_task_read ? ULONGLONG(tt->task_struct +
- OFFSET(task_struct_sched_info) +
- OFFSET(sched_info_last_arrival)) : 0;
else if (VALID_MEMBER(sched_entity_exec_start))
timestamp = tt->last_task_read ? ULONGLONG(tt->task_struct
+
OFFSET(task_struct_se) +
crash> help -o | grep -e task_struct_last_run -e task_struct_timestamp -e
sched_info_last_arrival -e sched_entity_exec_start
task_struct_last_run: -1
task_struct_timestamp: -1
sched_info_last_arrival: 16
sched_entity_exec_start: 72
crash> ps -l
[23601334315087174] [RU] PID: 4023608 TASK: ffff916f7c6b1840 CPU: 15 COMMAND:
"makedumpfile"
...
crash> task 4023608 | grep exec_start
exec_start = 23601334315087174,
Oh! thanks for sharing useful tips.
>
> I would like to remind that as commit description said, the patch is
> **only** valid
> without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO.
>
> When kernel image is with CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO and then
> "ps -l|-m" command is used, task_last_run() is called from its
subroutines.
>
> ulonglong
> task_last_run(ulong task)
> {
> ulong last_run;
> ...
> else if (VALID_MEMBER(sched_info_last_arrival)) // With
> CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO
> timestamp = tt->last_task_read ? ULONGLONG(tt->task_struct +
> OFFSET(task_struct_sched_info) +
> OFFSET(sched_info_last_arrival)) : 0;
> + else if (VALID_MEMBER(sched_entity_exec_start)) // Without
> CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO
> + timestamp = tt->last_task_read ? ULONGLONG(tt->task_struct +
> + OFFSET(task_struct_se) +
> + OFFSET(sched_entity_exec_start)) : 0;
>
> return timestamp;
> }
>
> With CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO enabled,
> the statement under 'VALID_MEMBER(sched_entity_exec_start)' is not called.
>
> > crash> ps -m | head
> > [ 0 00:59:36.582] [RU] PID: 4023608 TASK: ffff916f7c6b1840 CPU: 15
COMMAND: "makedumpfile"
> > ^^^^^^^^^(1)
> > [ 0 00:59:37.831] [ID] PID: 413 TASK: ffff916f772d3080 CPU: 15
COMMAND: "kworker/15:1H"
> > [ 0 00:59:39.765] [IN] PID: 3929504 TASK: ffff916f5f0748c0 CPU: 15
COMMAND: "respawn_actlog"
> > [ 0 00:59:40.650] [IN] PID: 1974 TASK: ffff91647dc53080 CPU: 15
COMMAND: "CPU 2/KVM"
> > [ 0 00:59:41.925] [IN] PID: 1297 TASK: ffff916f63c46100 CPU: 15
COMMAND: "NetworkManager"
> > [ 0 00:59:42.944] [ID] PID: 3763057 TASK: ffff9160c4519840 CPU: 15
COMMAND: "kworker/15:0"
> > [ 0 00:59:42.944] [IN] PID: 101 TASK: ffff916040c91840 CPU: 15
COMMAND: "migration/15"
> > [ 0 00:59:43.078] [IN] PID: 100 TASK: ffff916040c5b080 CPU: 15
COMMAND: "watchdog/15"
> > [ 0 00:59:47.533] [IN] PID: 1292 TASK: ffff916f63c43080 CPU: 15
COMMAND: "lsmd"
> > [ 0 00:59:49.089] [IN] PID: 113105 TASK: ffff9160412248c0 CPU: 15
COMMAND: "kvm-nx-lpage-re"
> > ^^^^^^^(2)
> > (1) large difference from zero
> > (2) large differences among CPUs (probably due to the differences of irq time)
> >
> > (1) might be solved with rq->clock_task, but (2) will be misleading and
confusing.
> > So currently I'm thinking that the "ps -l|-m" options should not
use the se.exec_start.
> > What do you think?
> >
>
> Agreed. (As you indicated) Since rq->clock cannot hold accurate
> timestamp we can rely on,
> "ps -l|-m" options should not access the se.exec_start in case of kernel
image
> without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO.
>
> Thanks for your code review.
> If there is something to improve, let me propose a patch again.
Sure.
I think that the se.exec_start itself may be somewhat useful, especially for
dumpfiles without CONFIG_SCHED{STATS,_INFO}, but not suitable for the current
"ps -l|-m" behavior. There may be another way to make good use of it.
Now that you consider se.exec_start to be useful indicator,
how about adding seperate option to ps(ex: "ps -e") which display all processes
sorted with most recently-run process based on se.exec_start?
This does not affect "ps -l|-m" output at all.
If you agree with this idea, let me send another patch soon.
Anyway thanks for feedback and great code review.
BR,
Austin Kim
Thanks,
Kazu
1:28 a.m.
-----Original Message-----
> > > crash> ps -m | head
> > > [ 0 00:59:36.582] [RU] PID: 4023608 TASK: ffff916f7c6b1840 CPU: 15
COMMAND: "makedumpfile"
> > > ^^^^^^^^^(1)
> > > [ 0 00:59:37.831] [ID] PID: 413 TASK: ffff916f772d3080 CPU: 15
COMMAND: "kworker/15:1H"
> > > [ 0 00:59:39.765] [IN] PID: 3929504 TASK: ffff916f5f0748c0 CPU: 15
COMMAND: "respawn_actlog"
> > > [ 0 00:59:40.650] [IN] PID: 1974 TASK: ffff91647dc53080 CPU: 15
COMMAND: "CPU 2/KVM"
> > > [ 0 00:59:41.925] [IN] PID: 1297 TASK: ffff916f63c46100 CPU: 15
COMMAND: "NetworkManager"
> > > [ 0 00:59:42.944] [ID] PID: 3763057 TASK: ffff9160c4519840 CPU: 15
COMMAND: "kworker/15:0"
> > > [ 0 00:59:42.944] [IN] PID: 101 TASK: ffff916040c91840 CPU: 15
COMMAND: "migration/15"
> > > [ 0 00:59:43.078] [IN] PID: 100 TASK: ffff916040c5b080 CPU: 15
COMMAND: "watchdog/15"
> > > [ 0 00:59:47.533] [IN] PID: 1292 TASK: ffff916f63c43080 CPU: 15
COMMAND: "lsmd"
> > > [ 0 00:59:49.089] [IN] PID: 113105 TASK: ffff9160412248c0 CPU: 15
COMMAND: "kvm-nx-lpage-re"
> > >
^^^^^^^(2)
> > > (1) large difference from zero
> > > (2) large differences among CPUs (probably due to the differences of irq
time)
> > >
> > > (1) might be solved with rq->clock_task, but (2) will be misleading and
confusing.
> > > So currently I'm thinking that the "ps -l|-m" options should
not use the se.exec_start.
> > > What do you think?
> > >
> >
> > Agreed. (As you indicated) Since rq->clock cannot hold accurate
> > timestamp we can rely on,
> > "ps -l|-m" options should not access the se.exec_start in case of
kernel image
> > without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO.
> >
> > Thanks for your code review.
> > If there is something to improve, let me propose a patch again.
>
> Sure.
>
> I think that the se.exec_start itself may be somewhat useful, especially for
> dumpfiles without CONFIG_SCHED{STATS,_INFO}, but not suitable for the current
> "ps -l|-m" behavior. There may be another way to make good use of it.
>
Now that you consider se.exec_start to be useful indicator,
how about adding seperate option to ps(ex: "ps -e") which display all
processes
sorted with most recently-run process based on se.exec_start?
Do you mean that it displays all processes together in a list sorted with
(rq->clock_task - se.exec_start)?
If so, personally I would not recommend it, because rq->clock{,_task} may not
be updated when a CPU stalls. I've seen such a vmcore occasionally, which
"runq -T" shows a big time lag on a CPU. In such a case, if they are sorted
with the above, the result will be misleading and hard to realize, I think.
(So it makes sense to me that the "ps -m" also sorts processes with the
value of last_arrival, not with (rq->clock - last_arrival).)
But adding a new option may be a possible way to use the se.exec_start.
If we do so, I would suggest to display processes for each CPU to avoid
misleading.
For example, you can see the -C with -l option display processes for
each CPU (with CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO):
crash> ps -l -C 0-1
CPU: 0
[23604910745100388] [IN] PID: 1332212 TASK: ffff916f76718000 CPU: 0 COMMAND:
"kvm-pit/1332189"
[23604909788870007] [IN] PID: 1950 TASK: ffff916eabc06100 CPU: 0 COMMAND:
"qemu-kvm"
[23604909299613494] [IN] PID: 2347388 TASK: ffff916d539e6100 CPU: 0 COMMAND:
"CPU 3/KVM"
...
CPU: 1
[23604910550325113] [IN] PID: 1744 TASK: ffff916f6e250000 CPU: 1 COMMAND:
"tuned"
...
Like the above, the new -e option displays processes for each CPU
without -C, in other words, it cannot display all processes in a list:
crash> ps -e
CPU: 0
[23597255887600040] [IN] PID: 1332212 TASK: ffff916f76718000 CPU: 0 COMMAND:
"kvm-pit/1332189"
[23597254932332895] [IN] PID: 1950 TASK: ffff916eabc06100 CPU: 0 COMMAND:
"qemu-kvm"
[23597254443638756] [IN] PID: 2347388 TASK: ffff916d539e6100 CPU: 0 COMMAND:
"CPU 3/KVM"
...
CPU: 1
[23599915368410083] [IN] PID: 1744 TASK: ffff916f6e250000 CPU: 1 COMMAND:
"tuned"
...
This is a possible way I think of. Do you think this is useful?
Thanks,
Kazu
This does not affect "ps -l|-m" output at all.
If you agree with this idea, let me send another patch soon.
Anyway thanks for feedback and great code review.
BR,
Austin Kim
> Thanks,
> Kazu
>
2 a.m.
Hello, Kazu
2022년 3월 8일 (화) 오후 4:28, HAGIO KAZUHITO(萩尾 一仁) <k-hagio-ab(a)nec.xn--com>-4f21ay07k 작성:
-----Original Message-----
> > > > crash> ps -m | head
> > > > [ 0 00:59:36.582] [RU] PID: 4023608 TASK: ffff916f7c6b1840 CPU:
15 COMMAND: "makedumpfile"
> > > > ^^^^^^^^^(1)
> > > > [ 0 00:59:37.831] [ID] PID: 413 TASK: ffff916f772d3080 CPU:
15 COMMAND: "kworker/15:1H"
> > > > [ 0 00:59:39.765] [IN] PID: 3929504 TASK: ffff916f5f0748c0 CPU:
15 COMMAND: "respawn_actlog"
> > > > [ 0 00:59:40.650] [IN] PID: 1974 TASK: ffff91647dc53080 CPU:
15 COMMAND: "CPU 2/KVM"
> > > > [ 0 00:59:41.925] [IN] PID: 1297 TASK: ffff916f63c46100 CPU:
15 COMMAND: "NetworkManager"
> > > > [ 0 00:59:42.944] [ID] PID: 3763057 TASK: ffff9160c4519840 CPU:
15 COMMAND: "kworker/15:0"
> > > > [ 0 00:59:42.944] [IN] PID: 101 TASK: ffff916040c91840 CPU:
15 COMMAND: "migration/15"
> > > > [ 0 00:59:43.078] [IN] PID: 100 TASK: ffff916040c5b080 CPU:
15 COMMAND: "watchdog/15"
> > > > [ 0 00:59:47.533] [IN] PID: 1292 TASK: ffff916f63c43080 CPU:
15 COMMAND: "lsmd"
> > > > [ 0 00:59:49.089] [IN] PID: 113105 TASK: ffff9160412248c0 CPU:
15 COMMAND: "kvm-nx-lpage-re"
> > > >
^^^^^^^(2)
> > > > (1) large difference from zero
> > > > (2) large differences among CPUs (probably due to the differences of
irq time)
> > > >
> > > > (1) might be solved with rq->clock_task, but (2) will be
misleading and confusing.
> > > > So currently I'm thinking that the "ps -l|-m" options
should not use the se.exec_start.
> > > > What do you think?
> > > >
> > >
> > > Agreed. (As you indicated) Since rq->clock cannot hold accurate
> > > timestamp we can rely on,
> > > "ps -l|-m" options should not access the se.exec_start in case
of kernel image
> > > without CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO.
> > >
> > > Thanks for your code review.
> > > If there is something to improve, let me propose a patch again.
> >
> > Sure.
> >
> > I think that the se.exec_start itself may be somewhat useful, especially for
> > dumpfiles without CONFIG_SCHED{STATS,_INFO}, but not suitable for the current
> > "ps -l|-m" behavior. There may be another way to make good use of
it.
> >
>
> Now that you consider se.exec_start to be useful indicator,
> how about adding seperate option to ps(ex: "ps -e") which display all
processes
> sorted with most recently-run process based on se.exec_start?
Do you mean that it displays all processes together in a list sorted with
(rq->clock_task - se.exec_start)?
If so, personally I would not recommend it, because rq->clock{,_task} may not
be updated when a CPU stalls. I've seen such a vmcore occasionally, which
"runq -T" shows a big time lag on a CPU. In such a case, if they are sorted
with the above, the result will be misleading and hard to realize, I think.
(So it makes sense to me that the "ps -m" also sorts processes with the
value of last_arrival, not with (rq->clock - last_arrival).)
But adding a new option may be a possible way to use the se.exec_start.
If we do so, I would suggest to display processes for each CPU to avoid
misleading.
For example, you can see the -C with -l option display processes for
each CPU (with CONFIG_SCHEDSTATS or CONFIG_SCHED_INFO):
crash> ps -l -C 0-1
CPU: 0
[23604910745100388] [IN] PID: 1332212 TASK: ffff916f76718000 CPU: 0 COMMAND:
"kvm-pit/1332189"
[23604909788870007] [IN] PID: 1950 TASK: ffff916eabc06100 CPU: 0 COMMAND:
"qemu-kvm"
[23604909299613494] [IN] PID: 2347388 TASK: ffff916d539e6100 CPU: 0 COMMAND:
"CPU 3/KVM"
...
CPU: 1
[23604910550325113] [IN] PID: 1744 TASK: ffff916f6e250000 CPU: 1 COMMAND:
"tuned"
...
Like the above, the new -e option displays processes for each CPU
without -C, in other words, it cannot display all processes in a list:
crash> ps -e
CPU: 0
[23597255887600040] [IN] PID: 1332212 TASK: ffff916f76718000 CPU: 0 COMMAND:
"kvm-pit/1332189"
[23597254932332895] [IN] PID: 1950 TASK: ffff916eabc06100 CPU: 0 COMMAND:
"qemu-kvm"
[23597254443638756] [IN] PID: 2347388 TASK: ffff916d539e6100 CPU: 0 COMMAND:
"CPU 3/KVM"
...
CPU: 1
[23599915368410083] [IN] PID: 1744 TASK: ffff916f6e250000 CPU: 1 COMMAND:
"tuned"
...
This is a possible way I think of. Do you think this is useful?
I guess 'ps -e' command is not useful in above cases.
I had better find other ways to improve crash-utility.
Thanks for valuable feedback and review. (:
BR,
Austin Kim
Thanks,
Kazu
>
> This does not affect "ps -l|-m" output at all.
> If you agree with this idea, let me send another patch soon.
>
> Anyway thanks for feedback and great code review.
>
> BR,
> Austin Kim
>
> > Thanks,
> > Kazu
> >
844
days inactive
854
days old
devel@lists.crash-utility.osci.io
8 comments
2 participants
participants (2)
-
Austin Kim -
HAGIO KAZUHITO(萩尾 一仁)