Re: [PATCH] libtracefs: Destroy synthetic and eprobes before other events

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 

On 18/10/2024 3:17 pm, Steven Rostedt wrote:

On Fri, 18 Oct 2024 10:13:11 +0100
Metin Kaya <metin.kaya@xxxxxxx> wrote:


On 17/10/2024 9:01 pm, Steven Rostedt wrote:

On Thu, 17 Oct 2024 09:38:35 +0100
Metin Kaya <metin.kaya@xxxxxxx> wrote:

I see one more failure in this section of unit tests:

     Test: tracefs_iterate_snapshot_events API ...FAILED
       1. tracefs-utest.c:235  - ret == sizeof(struct test_sample)
       2. tracefs-utest.c:235  - ret == sizeof(struct test_sample)
       3. tracefs-utest.c:235  - ret == sizeof(struct test_sample)


Does this occur without this patch? IOW, is this caused by this patch?


I thought there were 2 "tracefs-utest.c:235  - ret == sizeof(struct
test_sample)" failures before this patch and this patch increased the
number of failures by 1. However, this does not seem to be 100% correct.
I sometimes see only 1 failure, but then there are 2-3 of them.

I do trace-cmd reset && unmount before running the unit tests.


Yeah, this is probably something different.




I did run trace-cmd reset and unmounted my tracefs before running the
unit tests.
Please feel free to ignore if something is weirdly wrong in my setup.

Other than that -kind of existing- failure, the patch looks good to me
(e.g., trace-cmd unit tests are working fine).



Can you add a printf("ret = %d\n", ret) to find out what "ret" is?


Here is the output with printf's:

    ...
    Test: tracefs_iterate_snapshot_events API ...
line=237 i=87 path=n~_ cpu=55 value=2046397138 ret=-1
FAILED
      1. tracefs-utest.c:240  - ret == sizeof(struct test_sample)
    Test: tracefs_iterate_raw_events API ...
line=237 i=1444 path=~_ cpu=50 value=1150454427 ret=-1
FAILED
      1. tracefs-utest.c:240  - ret == sizeof(struct test_sample)
    Test: Follow events ...passed
    ...


Hmm, looking at the code, I think it should be using trace_marker_raw and
not trace_marker. Although I don't believe that will fix this, it is still
something that needs to be changed.

-	path = tracefs_instance_get_file(instance, "trace_marker");
+	path = tracefs_instance_get_file(instance, "trace_marker_raw");
"tracefs-utest.c:285" failure ("CU_TEST(test_array[i].value == 0)" check in iter_raw_events_on_cpu()) is printed hundreds of times (did not count exact number, but there were too many): 

    ...
    10058. tracefs-utest.c:285  - test_array[i].value == 0
    10059. tracefs-utest.c:285  - test_array[i].value == 0
    10060. tracefs-utest.c:285  - test_array[i].value == 0
    10061. tracefs-utest.c:285  - test_array[i].value == 0
    10062. tracefs-utest.c:285  - test_array[i].value == 0
    10063. tracefs-utest.c:285  - test_array[i].value == 0
    10064. tracefs-utest.c:290  - test_found == check



As trace_marker expects strings but trace_marker_raw takes binary data, and
we are writing binary data here.

Could you also add a "perror()" when it fails. The ret=-1 means the write
failed, so it would be good to know why it failed.


    Test: uprobes ...
line=2229 ename=utest_u
address=/libtracefs/utest/trace-utest:0x00000000000003e8 event=utest_u
system=utest format=arg1=$stack2 prefix=p type=0x000004 ret=-1

line=2229 ename=utest_r
address=/libtracefs/utest/trace-utest:0x00000000000003e8 event=utest_r
system=utest format=arg1=$retval prefix=r type=0x000008 ret=-1
FAILED
      1. tracefs-utest.c:2232  - ret == 0
      2. tracefs-utest.c:2232  - ret == 0


And this is the output with your "libtracefs utest: Fixes and new tests"
patch series [1]:

    Test: tracefs_iterate_raw_events API ...
line=237 i=2532 path=Db cpu=0 value=1144606227 ret=-1

line=237 i=1285 path=ו3b cpu=6 value=1157898007 ret=-1
FAILED
      1. tracefs-utest.c:240  - ret == sizeof(struct test_sample)
      2. tracefs-utest.c:240  - ret == sizeof(struct test_sample)
    Test: Follow events ...passed
    Test: Follow events clear ...passed
    Test: tracefs_tracers API ...passed
    Test: tracefs_local events API ...passed
    Test: tracefs_instances_walk API ...passed
    Test: tracefs_get_clock API ...passed
    Test: tracing on / off ...passed
    Test: tracing options ...passed
    Test: custom system directory ...passed
    Test: ftrace marker ...passed
    Test: kprobes ...passed
    Test: synthetic events ...passed
    Test: eprobes ...passed
    Test: uprobes ...
line=2249 ename=utest_u
address=/ssd/tracecmd-work/libtracefs/utest/trace-utest:0x00000000000003e8
event=utest_u system=utest format=arg1=$stack2 prefix=p type=0x000004 ret=-1

line=2249 ename=utest_r
address=/ssd/tracecmd-work/libtracefs/utest/trace-utest:0x00000000000003e8
event=utest_r system=utest format=arg1=$retval prefix=r type=0x000008 ret=-1
FAILED
      1. tracefs-utest.c:2252  - ret == 0
      2. tracefs-utest.c:2252  - ret == 0
    Test: multi probe test ...
line=2249 ename=utest_u
address=/ssd/tracecmd-work/libtracefs/utest/trace-utest:0x00000000000003e8
event=utest_u system=utest format=arg1=$stack2 prefix=p type=0x000004 ret=-1

line=2249 ename=utest_r
address=/ssd/tracecmd-work/libtracefs/utest/trace-utest:0x00000000000003e8
event=utest_r system=utest format=arg1=$retval prefix=r type=0x000008 ret=-1
FAILED
      1. tracefs-utest.c:2252  - ret == 0
      2. tracefs-utest.c:2252  - ret == 0


Can you tell me what is at line 2252 because I don't know what patches you
have applied, and 2252 in my code doesn't mean anything.


Added perror() and reran the unit tests:

  Test: tracefs_iterate_snapshot_events API ...
write(): Bad address
line=238 i=1854 path=C cpu=48 value=204815716 ret=-1
FAILED
    1. tracefs-utest.c:242  - ret == sizeof(struct test_sample)
  Test: tracefs_iterate_raw_events API ...
write(): Bad address
line=238 i=3387 path=VCȿX cpu=47 value=1880503296 ret=-1
write(): Bad address
line=238 i=1452 path=ZȿX cpu=10 value=1748578433 ret=-1
write(): Bad address
line=238 i=1257 path=:SX cpu=14 value=289785431 ret=-1
write(): Bad address
line=238 i=3373 pathC cpu=39 value=178899675 ret=-1
FAILED
    1. tracefs-utest.c:242  - ret == sizeof(struct test_sample)
    2. tracefs-utest.c:242  - ret == sizeof(struct test_sample)
    3. tracefs-utest.c:242  - ret == sizeof(struct test_sample)
    4. tracefs-utest.c:242  - ret == sizeof(struct test_sample)
  Test: Follow events ...passed
  ...
  Test: eprobes ...passed
  Test: uprobes ...
line=2251 ename=utest_u address=/ssd/tracecmd-work/libtracefs/utest/trace-utest:0x00000000000003e8 event=utest_u system=utest format=arg1=$stack2 prefix=p type=0x000004 ret=-1 line=2251 ename=utest_r address=/ssd/tracecmd-work/libtracefs/utest/trace-utest:0x00000000000003e8 event=utest_r system=utest format=arg1=$retval prefix=r type=0x000008 ret=-1 
FAILED
    1. tracefs-utest.c:2255  - ret == 0
    2. tracefs-utest.c:2255  - ret == 0
  Test: multi probe test ...
line=2251 ename=utest_u address=/ssd/tracecmd-work/libtracefs/utest/trace-utest:0x00000000000003e8 event=utest_u system=utest format=arg1=$stack2 prefix=p type=0x000004 ret=-1 line=2251 ename=utest_r address=/ssd/tracecmd-work/libtracefs/utest/trace-utest:0x00000000000003e8 event=utest_r system=utest format=arg1=$retval prefix=r type=0x000008 ret=-1 
FAILED
    1. tracefs-utest.c:2255  - ret == 0
    2. tracefs-utest.c:2255  - ret == 0


Snippet regarding "tracefs-utest.c:242" failure:

 227         for (i = 0; i < TEST_ARRAY_SIZE; i++) {
 228                 test_array[i].cpu = rand() % cpus;
229 test_array[i].value = random(); 
 230                 if (!test_array[i].value)
231 test_array[i].value++; 
 232                 CU_TEST(test_array[i].cpu < cpus);
 233                 set_affinity(test_array[i].cpu);
234 ret = write(fd, test_array + i, sizeof(struct test_sample)); 
 235                 if (ret != sizeof(struct test_sample)) {
236 perror("\nwrite()"); 237 printf("\nline=%d i=%d path=%s cpu=%d value=%d ret=%d\n", 
 238                                __LINE__,
239 i, path, test_array[i].cpu, test_array[i].value, 
 240                                ret);
 241                 }
 242                 CU_TEST(ret == sizeof(struct test_sample));


Snippet regarding "tracefs-utest.c:2255" failure:

2244                         if (probes[j].prefix) {
2245 CU_TEST(strcmp(probes[j].prefix, prefix) == 0); 
2246                         }
2247 ret = tracefs_event_enable(instance, system, event); 
2248                         if (in_system) {
2249                                 if (ret != 0) {
2250 printf("\nline=%d ename=%s address=%s event=%s system=%s format=%s prefix=%s type=%#08x ret=%d\n", 
2251                                                __LINE__,
2252 ename, address, event, system, format, prefix, type, 
2253                                                ret);
2254                                 }
2255                                 CU_TEST(ret == 0);
2256                         } else {
2257                                 if (ret == 0) {
2258 printf("\nline=%d ename=%s address=%s event=%s system=%s format=%s prefix=%s type=%#08x ret=%d\n", 
2259                                                __LINE__,
2260 ename, address, event, system, format, prefix, type, 
2261                                                ret);
2262                                 }
2263                                 CU_TEST(ret != 0);
2264                         }


I've these patches in my stash:
* 8468f2e - (HEAD -> libtracefs) libtracefs utest: Add debug logs <Metin Kaya> * cee05c1 - libtracefs utest: Do not test more events than what the ring buffer can hold <Steven Rostedt (Google)> 
* 385650c - libtracefs utest: Fix min percent test <Steven Rostedt (Google)>
* c0810b9 - libtracefs utest: Add test to check handling multiple dynamic events <Steven Rostedt (Google)> * d8fcfff - libtracefs: Destroy synthetic and eprobes before other events <Steven Rostedt (Google)> * 78d8d2e - (origin/libtracefs, origin/HEAD) libtracefs: Have tracefs_dynevent_get_all() find kprobes and uprobes properly <Steven Rostedt (Google)>
[Index of Archives]     [Linux USB Development]     [Linux USB Development]     [Linux Audio Users]     [Yosemite Hiking]     [Linux Kernel]     [Linux SCSI]

  Powered by Linux