Re: evl ps cpu time reporting issue

Giulio Moro <[email protected]> writes:

>> The most crucial one is that sometimes it reports excessive CPU usage, e.g. (running watch -n1 evl  ps -st):
>>  CPU   PID   ISW     CTXSW     SYS       RWA       STAT     TIMEOUT
>> %CPU      CPUTIME       NAME
>> ...
>>    0   1011  6640    31157     37608     23656      W          -         1193652.1      0:642.101    thread:947:0xffffb3c0fe30:2214587712
>> ...
>
>
> I forgot to mention that most of the time this thread reports 0% usage as expected. To confirm this is not an issue with libevl's visualisation, but the issue is somewhere deeper, one further log:
>
> # while sleep 0.1; do cat /sys/devices/virtual/thread/thread\:8011\:0xffff97cdfe30\:2491661632/stats; done
>
> 8926 41873 50471 29419 609329129 0
> 8927 41875 50474 29420 609388012 11133
> 8927 41876 50475 29420 609410796 0
> 8927 41878 50477 29420 609451945 0
> 8928 41880 50480 29420 609481429 0
> 8928 41881 50481 29420 609498449 0
> 8928 41883 50483 29420 609535063 0
> 8929 41886 50486 29420 609574946 0
> 8929 41887 50487 29420 609592925 0
> 8929 41889 50489 29420 609632058 1
> 8930 41891 50492 29420 609663628 0
> 8930 41892 50493 29420 609680457 0
> 8930 41894 50495 29420 609717002 0
> 8931 41896 50498 29420 609746761 0
> 8931 41897 50499 29420 609766180 0
> 8931 41898 50500 29420 609783920 0
> 8932 41901 50504 29420 609836897 0
> 8932 41902 50505 29420 609858481 0
> 8932 41903 50506 29420 609887230 0
> 8933 41906 50510 29420 609946013 20581947
> 8933 41907 50511 29421 609971602 0
> 8933 41908 50512 29422 609998161 0
> 8933 41909 50513 29423 610025640 0
> 8934 41912 50517 29424 610095202 5239
> 8934 41913 50518 29424 610113607 0
> 8934 41914 50519 29424 610137617 0
>
>
> Best,
> Giulio

Can you please add this patch to your kernel? This may help in figuring
out which input to the calculation is wrong.

diff --git a/kernel/evl/thread.c b/kernel/evl/thread.c
index 41c7505384ffc..3c1b08bb62b8d 100644
--- a/kernel/evl/thread.c
+++ b/kernel/evl/thread.c
@@ -2619,7 +2619,7 @@ static ssize_t stats_show(struct device *dev,
 			struct device_attribute *attr,
 			char *buf)
 {
-	ktime_t period, exectime, account, total;
+	ktime_t period, exectime, _exectime, account, _account, total;
 	struct evl_thread *thread;
 	unsigned long flags;
 	struct evl_rq *rq;
@@ -2650,6 +2650,8 @@ static ssize_t stats_show(struct device *dev,
 
 	raw_spin_unlock_irqrestore(&thread->lock, flags);
 
+	_exectime = exectime;
+	_account = account;
 	if (account) {
 		while (account > 0xffffffffUL) {
 			exectime >>= 16;
@@ -2662,13 +2664,13 @@ static ssize_t stats_show(struct device *dev,
 	} else
 		usage = 0;
 
-	ret = snprintf(buf, PAGE_SIZE, "%lu %lu %lu %lu %Lu %d\n",
+	ret = snprintf(buf, PAGE_SIZE, "%lu %lu %lu %lu %Lu %d %Lu %Lu\n",
 		evl_opt_counter_read(&thread->stat.isw),
 		evl_opt_counter_read(&thread->stat.csw),
 		evl_opt_counter_read(&thread->stat.sc),
 		evl_opt_counter_read(&thread->stat.rwa),
 		total,
-		usage);
+		usage, _exectime, _account);
 
 	evl_put_element(&thread->element);
 

-- 
Philippe.