Open Cosh-y opened 1 month ago
Hello, it fails unittest, I think it's because of the missing structure field in unittest.
If I fix it like below, there is no unittest fail, but I don't know if this is the best way to fix the fail. :)
diff --git a/utils/report.c b/utils/report.c
index 1bea5c75..dc54d9cb 100644
--- a/utils/report.c
+++ b/utils/report.c
@@ -1095,6 +1095,7 @@ TEST_CASE(report_sort)
struct rb_node *rbnode;
struct uftrace_report_node *node;
static struct uftrace_fstack fstack[TEST_NODES];
+ static struct uftrace_record r;
struct uftrace_data handle = {
.hdr = {
.max_stack = TEST_NODES,
@@ -1104,6 +1105,7 @@ TEST_CASE(report_sort)
struct uftrace_task_reader task = {
.h = &handle,
.func_stack = fstack,
+ .rstack = &r,
};
int i;
@@ -1207,14 +1209,17 @@ TEST_CASE(report_diff)
.nr_tasks = 2,
};
struct uftrace_fstack orig_fstack[TEST_NODES];
+ struct uftrace_record r;
struct uftrace_task_reader orig_task = {
.h = &handle,
.func_stack = orig_fstack,
+ .rstack = &r,
};
struct uftrace_fstack pair_fstack[TEST_NODES];
struct uftrace_task_reader pair_task = {
.h = &handle,
.func_stack = pair_fstack,
+ .rstack = &r,
};
const char *orig_name[] = { "abc", "foo", "bar" };
@@ -1314,3 +1319,4 @@ TEST_CASE(report_diff)
}
#endif /* UNIT_TEST */
+
It can be reproduced with make unittest ASAN=1 DEBUG=1 TESTARG="-v"
Thanks for @MichelleJin12 's suggestion. The failure of unittest is because of that I use task->rstack->time
in report_update_node()
when the testcase does not init tast.rstack
. I'm not clear about the test logic. I'm not sure if your patch valuable for testing or not.
Moreover, I found that the timestamp I print is always the same. I doubt if i set the timestamp correctly by timestamp = task->rstack->time - total_time;
in report_update_node()
. The output is always like this in my tests.
harry@harry-virtual-machine:~/Documents/C-Compilor-Test$ uftrace report -f total-max-ts,self-max-ts
Total max ts Self max ts Function
================== ================== ====================
331.253750424 331.253750424 main
331.253759126 331.253759126 __isoc99_scanf
334.663205183 334.663205183 printf
334.663204200 334.663204200 fibonacci
334.663219655 334.663219655 putchar
331.253744685 331.253744685 __monstartup
331.253747282 331.253747282 __cxa_atexit
I think you'll have to run uftrace record
again for the output to be different.
$ uftrace record ./a.out
$ uftrace report -f total-max-ts,self-max-ts,total,self,total-max,total-min
Total time Total min Total max Self time Total max ts Self max ts Function
========== ========== ========== ========== ================== ================== ====================
1.186 us 1.186 us 1.186 us 0.144 us 7971.631198721 7971.631198721 main
1.042 us 1.042 us 1.042 us 0.119 us 7971.631198807 7971.631198807 a
0.923 us 0.923 us 0.923 us 0.144 us 7971.631198871 7971.631198871 b
0.779 us 0.779 us 0.779 us 0.279 us 7971.631198924 7971.631198924 c
0.524 us 0.524 us 0.524 us 0.524 us 7971.631195215 7971.631195215 __monstartup
0.500 us 0.500 us 0.500 us 0.500 us 7971.631198989 7971.631198989 getpid
0.188 us 0.188 us 0.188 us 0.188 us 7971.631196827 7971.631196827 __cxa_atexit
$ uftrace replay -f time,delta
# TIMESTAMP TIMEDELTA FUNCTION
7971.631195215 | __monstartup();
7971.631196827 1.612 us | __cxa_atexit();
7971.631198721 1.894 us | main() {
7971.631198807 0.086 us | a() {
7971.631198871 0.064 us | b() {
7971.631198924 0.053 us | c() {
7971.631198989 0.065 us | getpid();
7971.631199703 0.714 us | } /* c */
7971.631199794 0.091 us | } /* b */
7971.631199849 0.055 us | } /* a */
7971.631199907 0.058 us | } /* main */
$ uftrace record ./a.out
$ uftrace report -f total-max-ts,self-max-ts,total,self,total-max,total-min
Total time Total min Total max Self time Total max ts Self max ts Function
========== ========== ========== ========== ================== ================== ====================
1.253 us 1.253 us 1.253 us 0.132 us 8090.845433163 8090.845433163 main
1.121 us 1.121 us 1.121 us 0.139 us 8090.845433237 8090.845433237 a
0.982 us 0.982 us 0.982 us 0.193 us 8090.845433307 8090.845433307 b
0.789 us 0.789 us 0.789 us 0.299 us 8090.845433362 8090.845433362 c
0.490 us 0.490 us 0.490 us 0.490 us 8090.845433428 8090.845433428 getpid
0.464 us 0.464 us 0.464 us 0.464 us 8090.845430594 8090.845430594 __monstartup
0.155 us 0.155 us 0.155 us 0.155 us 8090.845431766 8090.845431766 __cxa_atexit
$ uftrace replay -f time,delta
# TIMESTAMP TIMEDELTA FUNCTION
8090.845430594 | __monstartup();
8090.845431766 1.172 us | __cxa_atexit();
8090.845433163 1.397 us | main() {
8090.845433237 0.074 us | a() {
8090.845433307 0.070 us | b() {
8090.845433362 0.055 us | c() {
8090.845433428 0.066 us | getpid();
8090.845434151 0.723 us | } /* c */
8090.845434289 0.138 us | } /* b */
8090.845434358 0.069 us | } /* a */
8090.845434416 0.058 us | } /* main */
Hi @namhyung
According to the requirements in the issue #1898 , I have currently made a simple addition of four optional output fields: total-min-ts, total-max-ts, self-min-ts, and self-max-ts. Due to the longer field names, I have adjusted the output format accordingly.
The current problem is that the timestamp's starting time seems too early, resulting in excessively large timestamps. Additionally, the code hasn't passed through the pipeline yet, so I will further investigate the problem.
I hope you could review my work and provide valuable feedback.
Thank you very much!