per-thread exec-time stats

Hi,

I think to remember people crying for some execution time statistics for quite a while now. Here comes a straightforward approach to add this on a per-thread basis. The results are printed like this:

[email protected] :/root# cat /proc/xenomai/stat

CPU  PID    MSW        CSW        PF    STAT              TIME  NAME
  0  0      0          7508041    0     01400080     166038894  ROOT
  0  0      0          2          0     00000082            55  timsPipeReceiver
  0  1009   751        8800       0     00c00082        143026  display-1008
  0  1010   0          7514585    0     00c00084      54472477  sampling-1008

The new TIME column contains the accumulated execution time of each active thread in nanoseconds. It's now a job of some user-space tool (shell script?) to pick those

numbers up and do, e.g., periodic evaluation (I'm thinking of some "xeno-top"). Any volunteer around to hack this? Would be very welcome!

Jan

PS: Could someone have a look that I didn't miss an accounting point and my acquisition is sound?

PS: Could someone have a look that I didn't miss an accounting point and my acquisition is sound?

--

 include/nucleus/pod.h    |   28 ++++++++++++++++++++++++++++
 include/nucleus/thread.h |    1 +
 ksrc/nucleus/module.c    |   26 +++++++++++++++++++++-----
 ksrc/nucleus/pod.c       |    5 +++++
 ksrc/nucleus/thread.c    |    1 +
 5 files changed, 56 insertions(+), 5 deletions(-)

Index: include/nucleus/thread.h
===================================================================

nucleus/thread.h +1 -0

@@ -152,6 +152,7 @@ typedef struct xnthread {
 	unsigned long csw;	/* Context switches (includes
 				   secondary -> primary switches) */
 	unsigned long pf;	/* Number of page faults */
+	xnticks_t exec_time;	/* Accumulated execution time (ticks) */
     } stat;
 #endif /* CONFIG_XENO_OPT_STATS */
 

Index: include/nucleus/pod.h
===================================================================

nucleus/pod.h +4 -0

@@ -145,6 +145,10 @@ typedef struct xnsched {
 
     xnthread_t rootcb;          /*!< Root thread control block. */
 
+#ifdef CONFIG_XENO_OPT_STATS
+    xnticks_t last_csw;         /*!< Last context switch (ticks). */
+#endif /* CONFIG_XENO_OPT_STATS */
+
 } xnsched_t;
 
 #ifdef CONFIG_SMP

@@ -544,6 +548,30 @@ static inline void xnpod_delete_self (vo
     xnpod_delete_thread(xnpod_current_thread());

nucleus/pod.h +16 -0

+
+static inline void xnpod_update_csw_date(xnsched_t *sched)
+{
+    sched->last_csw = xntimer_get_rawclock();
+}
+#else /* !CONFIG_XENO_OPT_STATS */
+static inline void xnpod_acc_exec_time(xnsched_t *sched,
+                                       xnthread_t *threadout)
+{
+}
+
+static inline void xnpod_update_csw_date(xnsched_t *sched)
+{
+}
+#endif /* CONFIG_XENO_OPT_STATS */
+
 #ifdef __cplusplus
 }
 #endif

Index: ksrc/nucleus/thread.c
===================================================================

nucleus/thread.c +1 -0

@@ -90,6 +90,7 @@ int xnthread_init(xnthread_t *thread,
 	thread->stat.ssw = 0;
 	thread->stat.csw = 0;
 	thread->stat.pf = 0;
+	thread->stat.exec_time = 0;
 #endif /* CONFIG_XENO_OPT_STATS */
 
 	/* These will be filled by xnpod_start_thread() */

Index: ksrc/nucleus/pod.c
===================================================================

nucleus/pod.c +5 -0

@@ -669,6 +669,9 @@ static inline void xnpod_switch_zombie(x
 
 	xnthread_cleanup_tcb(threadout);
 
+	/* no need to update stats of dying thread */
+	xnpod_update_csw_date(sched);
+
 	xnarch_finalize_and_switch(xnthread_archtcb(threadout),
 				   xnthread_archtcb(threadin));
 

@@ -2431,6 +2434,7 @@ void xnpod_schedule(void)
 		xnarch_enter_root(xnthread_archtcb(threadin));
 	}
 
+	xnpod_acc_exec_time(sched, threadout);
 	xnthread_inc_csw(threadin);
 
 	xnarch_switch_to(xnthread_archtcb(threadout),

@@ -2602,6 +2606,7 @@ void xnpod_schedule_runnable(xnthread_t 
 		nkpod->schedhook(runthread, XNREADY);
 #endif /* __XENO_SIM__ */
 
+	xnpod_acc_exec_time(sched, runthread);
 	xnthread_inc_csw(threadin);
 
 	xnarch_switch_to(xnthread_archtcb(runthread),

Index: ksrc/nucleus/module.c
===================================================================

nucleus/module.c +10 -5

@@ -254,6 +254,7 @@ struct stat_seq_iterator {
 		unsigned long ssw;
 		unsigned long csw;
 		unsigned long pf;
+		xnticks_t exec_time;
 	} stat_info[1];
 };
 

@@ -294,13 +295,17 @@ static void stat_seq_stop(struct seq_fil
 static int stat_seq_show(struct seq_file *seq, void *v)
 {
 	if (v == SEQ_START_TOKEN)
-		seq_printf(seq, "%-3s  %-6s %-10s %-10s %-4s  %-8s  %s\n",
-			   "CPU", "PID", "MSW", "CSW", "PF", "STAT", "NAME");
+		seq_printf(seq, "%-3s  %-6s %-10s %-10s %-4s  %-8s  %12s"
+			   "  %s\n",
+			   "CPU", "PID", "MSW", "CSW", "PF", "STAT", "TIME",
+			   "NAME");
 	else {
 		struct stat_seq_info *p = (struct stat_seq_info *)v;
-		seq_printf(seq, "%3u  %-6d %-10lu %-10lu %-4lu  %.8lx  %s\n",
+		unsigned long long exec_time = xnpod_ticks2ns(p->exec_time);
+		seq_printf(seq, "%3u  %-6d %-10lu %-10lu %-4lu  %.8lx  %12llu"
+			   "  %s\n",
 			   p->cpu, p->pid, p->ssw, p->csw, p->pf, p->status,
-			   p->name);
+			   xnarch_ulldiv(exec_time, 1000, NULL), p->name);
 	}
 
 	return 0;

@@ -318,7 +323,7 @@ static int stat_seq_open(struct inode *i
 	struct stat_seq_iterator *iter;
 	struct seq_file *seq;
 	xnholder_t *holder;
-	int err, count;
+	int err, count, cpu;
 	spl_t s;
 
 	if (!nkpod)

@@ -341,6 +346,16 @@ static int stat_seq_open(struct inode *i
 
 	iter->nentries = 0;
 

nucleus/module.c +1 -0

 	/* Take a snapshot and release the nucleus lock immediately after,
 	   so that dumping /proc/xenomai/stat with lots of entries won't
 	   cause massive jittery. */

@@ -359,6 +374,7 @@ static int stat_seq_open(struct inode *i
 		iter->stat_info[n].ssw = thread->stat.ssw;
 		iter->stat_info[n].csw = thread->stat.csw;
 		iter->stat_info[n].pf = thread->stat.pf;
+		iter->stat_info[n].exec_time = thread->stat.exec_time;
 	}
 
 	xnlock_put_irqrestore(&nklock, s);

_______________________________________________
Xenomai-core mailing list
[email protected]
https://mail.gna.org/listinfo/xenomai-core

nucleus/module.c static void stat_seq_stop(struct seq_fil · line 308

Quoted 6 lines · Jan Kiszka

c_time);

nucleus/module.c +3 -1

+		seq_printf(seq, "%3u  %-6d %-10lu %-10lu %-4lu  %.8lx  %12llu"
+			   "  %s\n",
 			   p->cpu, p->pid, p->ssw, p->csw, p->pf, p->status,
-			   p->name);
+			   xnarch_ulldiv(exec_time, 1000, NULL), p->name);

xntimer_get_rawclock() returns TSC or jiffies, depending on the current aperiodic/periodic mode; what we need is something like xnarch_ulldiv(xnpod_ticks2ns(exec_time), ...)

On Thu, 2006-07-06 at 13:37 +0200, Jan Kiszka wrote:

<snip>

Quoted 43 lines

PS: Could someone have a look that I didn't miss an accounting point and my acquisition is sound?

--

 include/nucleus/pod.h    |   28 ++++++++++++++++++++++++++++
 include/nucleus/thread.h |    1 +
 ksrc/nucleus/module.c    |   26 +++++++++++++++++++++-----
 ksrc/nucleus/pod.c       |    5 +++++
 ksrc/nucleus/thread.c    |    1 +
 5 files changed, 56 insertions(+), 5 deletions(-)

Index: include/nucleus/thread.h
===================================================================

nucleus/thread.h +1 -0

@@ -152,6 +152,7 @@ typedef struct xnthread {
 	unsigned long csw;	/* Context switches (includes
 				   secondary -> primary switches) */
 	unsigned long pf;	/* Number of page faults */
+	xnticks_t exec_time;	/* Accumulated execution time (ticks) */
     } stat;
 #endif /* CONFIG_XENO_OPT_STATS */
 

Index: include/nucleus/pod.h
===================================================================

nucleus/pod.h +4 -0

@@ -145,6 +145,10 @@ typedef struct xnsched {
 
     xnthread_t rootcb;          /*!< Root thread control block. */
 
+#ifdef CONFIG_XENO_OPT_STATS
+    xnticks_t last_csw;         /*!< Last context switch (ticks). */
+#endif /* CONFIG_XENO_OPT_STATS */
+
 } xnsched_t;
 
 #ifdef CONFIG_SMP

@@ -544,6 +548,30 @@ static inline void xnpod_delete_self (vo
     xnpod_delete_thread(xnpod_current_thread());
 }
 

nucleus/pod.h static inline void xnpod_delete_self (vo · line 558

Quoted 8 lines

nucleus/pod.h +8 -0

+#ifdef CONFIG_XENO_OPT_STATS
+static inline void xnpod_acc_exec_time(xnsched_t *sched,
+                                       xnthread_t *threadout)
+{
+    xnticks_t now = xntimer_get_rawclock();
+    threadout->stat.exec_time += now - sched->last_csw;
+    sched->last_csw = now;
+}

It would be better to only pass the thread pointer, then use the thread->sched member. This would clearly explain the relationship between both, and prevent any bugous attempt at mixing things.

Quoted 109 lines

nucleus/pod.h +16 -0

+
+static inline void xnpod_update_csw_date(xnsched_t *sched)
+{
+    sched->last_csw = xntimer_get_rawclock();
+}
+#else /* !CONFIG_XENO_OPT_STATS */
+static inline void xnpod_acc_exec_time(xnsched_t *sched,
+                                       xnthread_t *threadout)
+{
+}
+
+static inline void xnpod_update_csw_date(xnsched_t *sched)
+{
+}
+#endif /* CONFIG_XENO_OPT_STATS */
+
 #ifdef __cplusplus
 }
 #endif

Index: ksrc/nucleus/thread.c
===================================================================

nucleus/thread.c +1 -0

@@ -90,6 +90,7 @@ int xnthread_init(xnthread_t *thread,
 	thread->stat.ssw = 0;
 	thread->stat.csw = 0;
 	thread->stat.pf = 0;
+	thread->stat.exec_time = 0;
 #endif /* CONFIG_XENO_OPT_STATS */
 
 	/* These will be filled by xnpod_start_thread() */

Index: ksrc/nucleus/pod.c
===================================================================

nucleus/pod.c +5 -0

@@ -669,6 +669,9 @@ static inline void xnpod_switch_zombie(x
 
 	xnthread_cleanup_tcb(threadout);
 
+	/* no need to update stats of dying thread */
+	xnpod_update_csw_date(sched);
+
 	xnarch_finalize_and_switch(xnthread_archtcb(threadout),
 				   xnthread_archtcb(threadin));
 

@@ -2431,6 +2434,7 @@ void xnpod_schedule(void)
 		xnarch_enter_root(xnthread_archtcb(threadin));
 	}
 
+	xnpod_acc_exec_time(sched, threadout);
 	xnthread_inc_csw(threadin);
 
 	xnarch_switch_to(xnthread_archtcb(threadout),

@@ -2602,6 +2606,7 @@ void xnpod_schedule_runnable(xnthread_t 
 		nkpod->schedhook(runthread, XNREADY);
 #endif /* __XENO_SIM__ */
 
+	xnpod_acc_exec_time(sched, runthread);
 	xnthread_inc_csw(threadin);
 
 	xnarch_switch_to(xnthread_archtcb(runthread),

Index: ksrc/nucleus/module.c
===================================================================

nucleus/module.c +10 -5

@@ -254,6 +254,7 @@ struct stat_seq_iterator {
 		unsigned long ssw;
 		unsigned long csw;
 		unsigned long pf;
+		xnticks_t exec_time;
 	} stat_info[1];
 };
 

@@ -294,13 +295,17 @@ static void stat_seq_stop(struct seq_fil
 static int stat_seq_show(struct seq_file *seq, void *v)
 {
 	if (v == SEQ_START_TOKEN)
-		seq_printf(seq, "%-3s  %-6s %-10s %-10s %-4s  %-8s  %s\n",
-			   "CPU", "PID", "MSW", "CSW", "PF", "STAT", "NAME");
+		seq_printf(seq, "%-3s  %-6s %-10s %-10s %-4s  %-8s  %12s"
+			   "  %s\n",
+			   "CPU", "PID", "MSW", "CSW", "PF", "STAT", "TIME",
+			   "NAME");
 	else {
 		struct stat_seq_info *p = (struct stat_seq_info *)v;
-		seq_printf(seq, "%3u  %-6d %-10lu %-10lu %-4lu  %.8lx  %s\n",
+		unsigned long long exec_time = xnpod_ticks2ns(p->exec_time);
+		seq_printf(seq, "%3u  %-6d %-10lu %-10lu %-4lu  %.8lx  %12llu"
+			   "  %s\n",
 			   p->cpu, p->pid, p->ssw, p->csw, p->pf, p->status,
-			   p->name);
+			   xnarch_ulldiv(exec_time, 1000, NULL), p->name);
 	}
 
 	return 0;

@@ -318,7 +323,7 @@ static int stat_seq_open(struct inode *i
 	struct stat_seq_iterator *iter;
 	struct seq_file *seq;
 	xnholder_t *holder;
-	int err, count;
+	int err, count, cpu;
 	spl_t s;
 
 	if (!nkpod)

@@ -341,6 +346,16 @@ static int stat_seq_open(struct inode *i
 
 	iter->nentries = 0;
 

nucleus/module.c static int stat_seq_open(struct inode *i · line 358

Quoted 10 lines

nucleus/module.c +10 -0

+	/* update exec-time stats of currently running threads */
+	for_each_online_cpu(cpu) {
+		xnsched_t *sched;
+
+		xnlock_get_irqsave(&nklock, s);
+		sched = xnpod_sched_slot(cpu);
+		xnpod_acc_exec_time(sched, sched->runthread);
+		xnlock_put_irqrestore(&nklock, s);
+	}
+

We could do that from the current loop below, given that the accumulation routine is changed to use thread->sched implicitely.

Quoted 19 lines

nucleus/module.c +1 -0

 	/* Take a snapshot and release the nucleus lock immediately after,
 	   so that dumping /proc/xenomai/stat with lots of entries won't
 	   cause massive jittery. */

@@ -359,6 +374,7 @@ static int stat_seq_open(struct inode *i
 		iter->stat_info[n].ssw = thread->stat.ssw;
 		iter->stat_info[n].csw = thread->stat.csw;
 		iter->stat_info[n].pf = thread->stat.pf;
+		iter->stat_info[n].exec_time = thread->stat.exec_time;
 	}
 
 	xnlock_put_irqrestore(&nklock, s);

_______________________________________________
Xenomai-core mailing list
[email protected]
https://mail.gna.org/listinfo/xenomai-core

Quoted 2 lines

We could do that from the current loop below, given that the accumulation routine is changed to use thread->sched implicitely.

The idea is avoid adding even further load to the nklock-protected loop. And we only update the current thread, not each and every.

Quoted 19 lines

Quoted 19 lines

nucleus/module.c +1 -0

 	/* Take a snapshot and release the nucleus lock immediately after,
 	   so that dumping /proc/xenomai/stat with lots of entries won't
 	   cause massive jittery. */

@@ -359,6 +374,7 @@ static int stat_seq_open(struct inode *i
 		iter->stat_info[n].ssw = thread->stat.ssw;
 		iter->stat_info[n].csw = thread->stat.csw;
 		iter->stat_info[n].pf = thread->stat.pf;
+		iter->stat_info[n].exec_time = thread->stat.exec_time;
 	}
 
 	xnlock_put_irqrestore(&nklock, s);

_______________________________________________
Xenomai-core mailing list
[email protected]
https://mail.gna.org/listinfo/xenomai-core

Quoted 5 lines · Jan Kiszka

Quoted 2 lines

We could do that from the current loop below, given that the accumulation routine is changed to use thread->sched implicitely.

The idea is avoid adding even further load to the nklock-protected loop. And we only update the current thread, not each and every.

Yes, but why? I mean, accumulated time so far remains significant even for non-running threads.

Quoted 8 lines · Philippe Gerum

Quoted 5 lines · Jan Kiszka

Quoted 2 lines

We could do that from the current loop below, given that the accumulation routine is changed to use thread->sched implicitely.

The idea is avoid adding even further load to the nklock-protected loop. And we only update the current thread, not each and every.

Yes, but why? I mean, accumulated time so far remains significant even for non-running threads.

Update must only happen for the currently running thread on each cpu, otherwise you skew the stats up.

But looking at the whole code in stat_seq_open() again, I now wonder if that whole routine isn't

a) fragile on task removal and
b) still poorly scaling.

The thread name is only copied by reference, a disappearing instance my cause troubles on printing it. And, instead of holding the lock all the time, shouldn't we better

1. pick some element from the queue and mark it somehow in-use under lock
2. print or copy the entry
3. reacquire the lock to proceed to the next one - after checking if that element happened to be removed from the queue meanwhile (in that case we could abort the output or try to resync)

Quoted 7 lines · Philippe Gerum

Quoted 5 lines · Jan Kiszka

Quoted 2 lines

We could do that from the current loop below, given that the accumulation routine is changed to use thread->sched implicitely.

The idea is avoid adding even further load to the nklock-protected loop. And we only update the current thread, not each and every.

Quoted 2 lines

Yes, but why? I mean, accumulated time so far remains significant even for non-running threads.

Update must only happen for the currently running thread on each cpu, otherwise you skew the stats up.

But looking at the whole code in stat_seq_open() again, I now wonder if that whole routine isn't

a) fragile on task removal and
b) still poorly scaling.

The thread name is only copied by reference, a disappearing instance my cause troubles on printing it.

And, instead of holding the lock all the
time, shouldn't we better

1. pick some element from the queue and mark it somehow in-use under lock
2. print or copy the entry
3. reacquire the lock to proceed to the next one - after checking if that element happened to be removed from the queue meanwhile

(in that
case we could abort the output or try to resync)

I'm worrying about a potential nice xeno-top tool polling the stats at high frequency and causing unexpected jitters if there are a significant number tasks registered (think of passive shadows we may create automatically in the future!).

Jan

Quoted 28 lines · Jan Kiszka

Quoted 5 lines · Philippe Gerum

Quoted 3 lines · Jan Kiszka

Quoted 3 lines

We could do that from the current loop below, given that the accumulation routine is changed to use thread->sched implicitely.

Quoted 7 lines

Quoted 4 lines

The idea is avoid adding even further load to the nklock-protected loop. And we only update the current thread, not each and every.

Yes, but why? I mean, accumulated time so far remains significant even for non-running threads.

Update must only happen for the currently running thread on each cpu, otherwise you skew the stats up.

But looking at the whole code in stat_seq_open() again, I now wonder if that whole routine isn't

a) fragile on task removal and
b) still poorly scaling.

The thread name is only copied by reference, a disappearing instance my cause troubles on printing it. And, instead of holding the lock all the time, shouldn't we better

Quoted 7 lines

1. pick some element from the queue and mark it somehow in-use under lock
2. print or copy the entry
3. reacquire the lock to proceed to the next one - after checking if that element happened to be removed from the queue meanwhile (in that case we could abort the output or try to resync)

Not feasible (threads may not always be prevented from being deleted), but what about this:

- maintain a modification counter for nkpod->threadq
- in our /proc-loops (sched and latency e.g.):
1. take nklock
2. get current counter
3. compare with previous, restart whole loop if not matching
4. copy current element (including the name...)
5. forward element pointer
6. release nklock
7. goto 1 if not end-of-list

As modifications on threadq should be fairly rare, I don't see a risk of looping endlessly here.

Quoted 4 lines

nucleus/pod.h +4 -0

+#ifdef CONFIG_XENO_OPT_STATS
+static inline void xnpod_acc_exec_time(xnsched_t *sched,
+                                       xnthread_t *threadout)
+{

nucleus/pod.h static inline void xnpod_delete_self (vo · line 558

Quoted 4 lines

nucleus/pod.h +4 -0

+    xnticks_t now = xntimer_get_rawclock();
+    threadout->stat.exec_time += now - sched->last_csw;
+    sched->last_csw = now;
+}

It would be better to only pass the thread pointer, then use the thread->sched member. This would clearly explain the relationship between both, and prevent any bugous attempt at mixing things.

Quoted 4 lines · Philippe Gerum

Quoted 4 lines

nucleus/pod.h +4 -0

+#ifdef CONFIG_XENO_OPT_STATS
+static inline void xnpod_acc_exec_time(xnsched_t *sched,
+                                       xnthread_t *threadout)
+{

Quoted 8 lines

nucleus/pod.h static inline void xnpod_delete_self (vo · line 558

Quoted 4 lines

nucleus/pod.h +4 -0

+    xnticks_t now = xntimer_get_rawclock();
+    threadout->stat.exec_time += now - sched->last_csw;
+    sched->last_csw = now;
+}

It would be better to only pass the thread pointer, then use the thread->sched member. This would clearly explain the relationship between both, and prevent any bugous attempt at mixing things.

Beware, when xnpod_schedule is called from within xnpod_migrate_thread(), the sched pointer of the switched out thread is the one of the destination cpu. So, passing the sched and threadout pointers to xnpod_acc_exec_time is safer.

Quoted 24 lines · Jan Kiszka

Quoted 8 lines · Philippe Gerum

Quoted 5 lines · Jan Kiszka

Quoted 2 lines

We could do that from the current loop below, given that the accumulation routine is changed to use thread->sched implicitely.

The idea is avoid adding even further load to the nklock-protected loop. And we only update the current thread, not each and every.

Yes, but why? I mean, accumulated time so far remains significant even for non-running threads.

Update must only happen for the currently running thread on each cpu, otherwise you skew the stats up.

But looking at the whole code in stat_seq_open() again, I now wonder if that whole routine isn't

a) fragile on task removal and
b) still poorly scaling.

The thread name is only copied by reference, a disappearing instance my cause troubles on printing it. And, instead of holding the lock all the time, shouldn't we better

Quoted 6 lines

1. pick some element from the queue and mark it somehow in-use under lock
2. print or copy the entry
3. reacquire the lock to proceed to the next one - after checking if that element happened to be removed from the queue meanwhile (in that case we could abort the output or try to resync)

Not feasible (threads may not always be prevented from being deleted), but what about this:

- maintain a modification counter for nkpod->threadq
- in our /proc-loops (sched and latency e.g.):
1. take nklock
2. get current counter
3. compare with previous, restart whole loop if not matching
4. copy current element (including the name...)
5. forward element pointer
6. release nklock
7. goto 1 if not end-of-list

As modifications on threadq should be fairly rare, I don't see a risk of looping endlessly here.

Jan

Quoted 43 lines · Jan Kiszka

Quoted 23 lines · Jan Kiszka

Quoted 8 lines · Philippe Gerum

Quoted 5 lines · Jan Kiszka

Quoted 2 lines

We could do that from the current loop below, given that the accumulation routine is changed to use thread->sched implicitely.

The idea is avoid adding even further load to the nklock-protected loop. And we only update the current thread, not each and every.

Yes, but why? I mean, accumulated time so far remains significant even for non-running threads.

Update must only happen for the currently running thread on each cpu, otherwise you skew the stats up.

But looking at the whole code in stat_seq_open() again, I now wonder if that whole routine isn't

a) fragile on task removal and
b) still poorly scaling.

The thread name is only copied by reference, a disappearing instance my cause troubles on printing it. And, instead of holding the lock all the time, shouldn't we better

Quoted 6 lines

1. pick some element from the queue and mark it somehow in-use under lock
2. print or copy the entry
3. reacquire the lock to proceed to the next one - after checking if that element happened to be removed from the queue meanwhile (in that case we could abort the output or try to resync)

Not feasible (threads may not always be prevented from being deleted), but what about this:

- maintain a modification counter for nkpod->threadq
- in our /proc-loops (sched and latency e.g.):
1. take nklock
2. get current counter
3. compare with previous, restart whole loop if not matching
4. copy current element (including the name...)
5. forward element pointer
6. release nklock
7. goto 1 if not end-of-list

Quoted 3 lines

As modifications on threadq should be fairly rare, I don't see a risk of looping endlessly here.

The more I think of it, the more I'm convinced that we are trying to tweak /proc/xenomai/stats for the wrong purpose. Actually, some xeno_top tool would rather need the equivalent of individual /proc/<pid> files, thus reducing the contention on access, and the need for weird grepping on the output. e.g. /proc/xenomai/threads/<pid> could emit per-thread data in some easily greppable form by a user-space tool.

Here is such a patch + a reworked version of the exec-time stats. Compiles and boots, doesn't cause obvious troubles when running in a loop while threads are created and destroyed in parallel. Nevertheless, a quick hack which may contain bugs.

Quoted 48 lines · Philippe Gerum

Quoted 43 lines · Jan Kiszka

Quoted 23 lines · Jan Kiszka

Quoted 8 lines · Philippe Gerum

Quoted 5 lines · Jan Kiszka

Quoted 2 lines

We could do that from the current loop below, given that the accumulation routine is changed to use thread->sched implicitely.

The idea is avoid adding even further load to the nklock-protected loop. And we only update the current thread, not each and every.

Yes, but why? I mean, accumulated time so far remains significant even for non-running threads.

Update must only happen for the currently running thread on each cpu, otherwise you skew the stats up.

But looking at the whole code in stat_seq_open() again, I now wonder if that whole routine isn't

a) fragile on task removal and
b) still poorly scaling.

The thread name is only copied by reference, a disappearing instance my cause troubles on printing it. And, instead of holding the lock all the time, shouldn't we better

Quoted 6 lines

1. pick some element from the queue and mark it somehow in-use under lock
2. print or copy the entry
3. reacquire the lock to proceed to the next one - after checking if that element happened to be removed from the queue meanwhile (in that case we could abort the output or try to resync)

Not feasible (threads may not always be prevented from being deleted), but what about this:

- maintain a modification counter for nkpod->threadq
- in our /proc-loops (sched and latency e.g.):
1. take nklock
2. get current counter
3. compare with previous, restart whole loop if not matching
4. copy current element (including the name...)
5. forward element pointer
6. release nklock
7. goto 1 if not end-of-list

Quoted 3 lines

As modifications on threadq should be fairly rare, I don't see a risk of looping endlessly here.

Quoted 6 lines

The more I think of it, the more I'm convinced that we are trying to tweak /proc/xenomai/stats for the wrong purpose. Actually, some xeno_top tool would rather need the equivalent of individual /proc/<pid> files, thus reducing the contention on access, and the need for weird grepping on the output. e.g. /proc/xenomai/threads/<pid> could emit per-thread data in some easily greppable form by a user-space tool.

Far too complex in my eyes for this simple purpose (what's the pid of kernel-only threads?) -

and we need to solve the latency problem of
/sched and /stat anyway.

Jan

Quoted 54 lines · Jan Kiszka

Quoted 53 lines · Philippe Gerum

Quoted 43 lines · Jan Kiszka

Quoted 23 lines · Jan Kiszka

Quoted 8 lines · Philippe Gerum

Quoted 5 lines · Jan Kiszka

Quoted 2 lines

We could do that from the current loop below, given that the accumulation routine is changed to use thread->sched implicitely.

The idea is avoid adding even further load to the nklock-protected loop. And we only update the current thread, not each and every.

Yes, but why? I mean, accumulated time so far remains significant even for non-running threads.

Update must only happen for the currently running thread on each cpu, otherwise you skew the stats up.

But looking at the whole code in stat_seq_open() again, I now wonder if that whole routine isn't

a) fragile on task removal and
b) still poorly scaling.

The thread name is only copied by reference, a disappearing instance my cause troubles on printing it. And, instead of holding the lock all the time, shouldn't we better

Quoted 6 lines

1. pick some element from the queue and mark it somehow in-use under lock
2. print or copy the entry
3. reacquire the lock to proceed to the next one - after checking if that element happened to be removed from the queue meanwhile (in that case we could abort the output or try to resync)

Not feasible (threads may not always be prevented from being deleted), but what about this:

- maintain a modification counter for nkpod->threadq
- in our /proc-loops (sched and latency e.g.):
1. take nklock
2. get current counter
3. compare with previous, restart whole loop if not matching
4. copy current element (including the name...)
5. forward element pointer
6. release nklock
7. goto 1 if not end-of-list

Quoted 3 lines

As modifications on threadq should be fairly rare, I don't see a risk of looping endlessly here.

The more I think of it, the more I'm convinced that we are trying to tweak /proc/xenomai/stats for the wrong purpose. Actually, some xeno_top tool would rather need the equivalent of individual /proc/<pid> files, thus reducing the contention on access, and the need for weird grepping on the output. e.g. /proc/xenomai/threads/<pid> could emit per-thread data in some easily greppable form by a user-space tool.

Quoted 2 lines

Far too complex in my eyes for this simple purpose (what's the pid of kernel-only threads?) -

It's symbolic name. It's not a matter of simplicity, your patch for that purpose is rather complex already.

Quoted 3 lines

and we need to solve the latency problem of
/sched and /stat anyway.

That's separate issues. Solving the scalability issue
of /proc/xenomai/stats and friends does not improve their usability in the context of user-space tools monitoring thread activity. E.g. how are we going to extend the reporting about such activity if need be, adding yet another column to /stats and /sched?

Quoted 14 lines · Gilles Chanteperdrix

Quoted 12 lines · Philippe Gerum

nucleus/pod.h static inline void xnpod_delete_self (vo · line 558

Quoted 8 lines

nucleus/pod.h +8 -0

+#ifdef CONFIG_XENO_OPT_STATS
+static inline void xnpod_acc_exec_time(xnsched_t *sched,
+                                       xnthread_t *threadout)
+{
+    xnticks_t now = xntimer_get_rawclock();
+    threadout->stat.exec_time += now - sched->last_csw;
+    sched->last_csw = now;
+}

It would be better to only pass the thread pointer, then use the thread->sched member. This would clearly explain the relationship between both, and prevent any bugous attempt at mixing things.

Quoted 4 lines

Beware, when xnpod_schedule is called from within xnpod_migrate_thread(), the sched pointer of the switched out thread is the one of the destination cpu. So, passing the sched and threadout pointers to xnpod_acc_exec_time is safer.

Nope, the nklock is held by the migrating thread all along until the switch has actually occured.

Quoted 20 lines · Philippe Gerum

Quoted 18 lines · Gilles Chanteperdrix

Quoted 4 lines · Philippe Gerum

Quoted 4 lines

nucleus/pod.h +4 -0

+#ifdef CONFIG_XENO_OPT_STATS
+static inline void xnpod_acc_exec_time(xnsched_t *sched,
+                                       xnthread_t *threadout)
+{

Quoted 8 lines

nucleus/pod.h static inline void xnpod_delete_self (vo · line 558

Quoted 4 lines

nucleus/pod.h +4 -0

+    xnticks_t now = xntimer_get_rawclock();
+    threadout->stat.exec_time += now - sched->last_csw;
+    sched->last_csw = now;
+}

It would be better to only pass the thread pointer, then use the thread->sched member. This would clearly explain the relationship between both, and prevent any bugous attempt at mixing things.

Beware, when xnpod_schedule is called from within xnpod_migrate_thread(), the sched pointer of the switched out thread is the one of the destination cpu. So, passing the sched and threadout pointers to xnpod_acc_exec_time is safer.

Quoted 2 lines

Nope, the nklock is held by the migrating thread all along until the switch has actually occured.

xnpod_acc_exec_time() is called from within xnpod_schedule() that is called from within xnpod_migrate_thread() at a time where threadout->sched is the wrong pointer.

Quoted 5 lines

Quoted 2 lines

Far too complex in my eyes for this simple purpose (what's the pid of kernel-only threads?) -

It's symbolic name. It's not a matter of simplicity, your patch for that purpose is rather complex already.

Haven't measured, but the amount of code added for collecting the data and printing just another column should be marginal as yet. Introducing a new infrastructure for more /proc subdirs with probably multiple entries would certainly cost more.

Quoted 9 lines

Quoted 3 lines

and we need to solve the latency problem of
/sched and /stat anyway.

That's separate issues. Solving the scalability issue
of /proc/xenomai/stats and friends does not improve their usability in the context of user-space tools monitoring thread activity. E.g. how are we going to extend the reporting about such activity if need be, adding yet another column to /stats and /sched?

As long as there are no stand-alone tools relying on the layout, just only our own ones - fairly simple. But before speculating more, I will have a look now how simple such tool/script may actually be.

Jan

Quoted 20 lines · Philippe Gerum

Quoted 18 lines · Gilles Chanteperdrix

Quoted 4 lines · Philippe Gerum

Quoted 4 lines

nucleus/pod.h +4 -0

+#ifdef CONFIG_XENO_OPT_STATS
+static inline void xnpod_acc_exec_time(xnsched_t *sched,
+                                       xnthread_t *threadout)
+{

Quoted 8 lines

nucleus/pod.h static inline void xnpod_delete_self (vo · line 558

Quoted 4 lines

nucleus/pod.h +4 -0

+    xnticks_t now = xntimer_get_rawclock();
+    threadout->stat.exec_time += now - sched->last_csw;
+    sched->last_csw = now;
+}

It would be better to only pass the thread pointer, then use the thread->sched member. This would clearly explain the relationship between both, and prevent any bugous attempt at mixing things.

Beware, when xnpod_schedule is called from within xnpod_migrate_thread(), the sched pointer of the switched out thread is the one of the destination cpu. So, passing the sched and threadout pointers to xnpod_acc_exec_time is safer.

Quoted 2 lines

Nope, the nklock is held by the migrating thread all along until the switch has actually occured.

xnpod_acc_exec_time() is called from within xnpod_schedule() that is called from within xnpod_migrate_thread() at a time where threadout->sched is the wrong pointer.

Quoted 3 lines

xnpod_acc_exec_time() is called from within xnpod_schedule() that is called from within xnpod_migrate_thread() at a time where threadout->sched is the wrong pointer.

Gasp. Unfortunately, we are trapped by an exception case, and I don't see any better approach.

Quoted 4 lines · Philippe Gerum

Quoted 3 lines

xnpod_acc_exec_time() is called from within xnpod_schedule() that is called from within xnpod_migrate_thread() at a time where threadout->sched is the wrong pointer.

Quoted 2 lines

Gasp. Unfortunately, we are trapped by an exception case, and I don't see any better approach.

We could reimplement an xnpod_migrate_thread() which suspend the calling thread and wake up a server thread on the destination CPU, this server thread migrating the suspended thread by changing its sched pointer outside of xnpod_schedule().

Or we can get rid of xnpod_migrate_thread(), it is currently not used by any skin.