* [Questions][trace-cmd/libtraceevent] how to correctly parse info out from specifial format of event?
@ 2022-01-13 8:20 Chen, Hongzhan
[not found] ` <20220113140952.34d0f937@gandalf.local.home>
0 siblings, 1 reply; 6+ messages in thread
From: Chen, Hongzhan @ 2022-01-13 8:20 UTC (permalink / raw)
To: linux-trace-devel; +Cc: Kiszka, Jan
When I tried to analysis trace log that captured from xenomai system with kernelshark, I found
that it report "FAILED TO PARSE" for some events. These events have format like [1].
In trace, these events would be printed like [2].
At first, I was trying to develop new libtraceevent plugin to parse this event correctly.
When I refer to code plugins/plugin_mac80211.c of libtraceevent to parse field param_ex
out for this __data_loc type of data, I always get value 0x380018 and It is supposed to trace_seq_printf
0x38 size of string got from offset 0x18 of tep_record->data but it fail. After debug, I found
that the data start from offset 0x18 is not what we expect and first few bytes of data is like [3].
It seems that data stored for field param_ex is quite different from what we expect.
How could I look into trace-cmd related code to fix such issue? Any suggestions?
Thanks for your help in advance.
[1]:
root@ecs-xenomai-isar:~# cat /sys/kernel/debug/tracing/events/cobalt_posix/cobalt_pthread_create/format
name: cobalt_pthread_create
ID: 628
format:
field:unsigned short common_type; offset:0; size:2; signed:0;
field:unsigned char common_flags; offset:2; size:1; signed:0;
field:unsigned char common_preempt_count; offset:3; size:1; signed:0;
field:int common_pid; offset:4; size:4; signed:1;
field:unsigned long pth; offset:8; size:8; signed:0;
field:int policy; offset:16; size:4; signed:1;
field:__data_loc char[] param_ex; offset:20; size:4; signed:1;
print fmt: "pth=%p policy=%s param=' %s '", (void *)REC->pth, __print_symbolic(REC->policy,
{0, "normal"}, {1, "fifo"}, {2, "rr"}, {11, "tp"}, {12, "quota"}, {10, "sporadic"}, {42, "cobalt"},
{43, "weak"}), cobalt_trace_parse_sched_params(p, REC->policy, (struct sched_param_ex *)(__get_dynamic_array(param_ex)))
[2]:
smokey-752 [000] d.~2 7970.727466: cobalt_pthread_getschedparam: pth=000000009bbc7fe0 policy=fifo param={ priority=50 }
smokey-762 [000] .... 7970.727492: cobalt_pthread_create: pth=00000000983468a5 policy=quota param={ priority=1, group=0 }
[3]:
0x1 0x0 0x0 0x0 0x0 0x0 0x0 0x0
Regards
Hongzhan Chen
^ permalink raw reply [flat|nested] 6+ messages in thread
* RE: [Questions][trace-cmd/libtraceevent] how to correctly parse info out from specifial format of event?
[not found] ` <20220113140952.34d0f937@gandalf.local.home>
@ 2022-01-14 1:37 ` Chen, Hongzhan
2022-01-14 2:06 ` Steven Rostedt
0 siblings, 1 reply; 6+ messages in thread
From: Chen, Hongzhan @ 2022-01-14 1:37 UTC (permalink / raw)
To: Steven Rostedt; +Cc: linux-trace-devel@vger.kernel.org>, Kiszka, Kiszka, Jan
>
>-----Original Message-----
>From: Steven Rostedt <rostedt@goodmis.org>
>Sent: Friday, January 14, 2022 3:10 AM
>To: Chen, Hongzhan <hongzhan.chen@intel.com>
>Cc: linux-trace-devel@vger.kernel.org" <linux-trace-devel@vger.kernel.org>, Kiszka; Jan <jan.kiszka@siemens.com>
>Subject: Re: [Questions][trace-cmd/libtraceevent] how to correctly parse info out from specifial format of event?
>
>On Thu, 13 Jan 2022 08:20:16 +0000
>"Chen, Hongzhan" <hongzhan.chen@intel.com> wrote:
>
>> When I tried to analysis trace log that captured from xenomai system with kernelshark, I found
>> that it report "FAILED TO PARSE" for some events. These events have format like [1].
>> In trace, these events would be printed like [2].
>> At first, I was trying to develop new libtraceevent plugin to parse this event correctly.
>> When I refer to code plugins/plugin_mac80211.c of libtraceevent to parse field param_ex
>> out for this __data_loc type of data, I always get value 0x380018 and It is supposed to trace_seq_printf
>> 0x38 size of string got from offset 0x18 of tep_record->data but it fail. After debug, I found
>> that the data start from offset 0x18 is not what we expect and first few bytes of data is like [3].
>>
>
>Could show me a full binary dump of the data for the record in your plugin?
>
>That is, something like this:
>
>tep_register_event_handler(tep, -1, "cobalt_posix",
> "cobalt_pthread_create",
> dump_event, NULL);
>
>
>static int dump_event(struct trace_seq *s,
> struct tep_record *record,
> struct tep_event *event, void *context)
>{
> unsigned char c;
> int i;
>
> for (i = 0; i < record->size; i++) {
> c = *(unsigned char *)(record->data + i);
> trace_seq_printf(s, "%02x", c);
> if (i < record->size - 1) {
> if ((i & 0x7) == 7)
> trace_seq_puts(s, " ");
> else
> trace_seq_putc(s, ' ');
> }
> }
> return 0;
>}
>
Following is two dumps, please check:
smokey-447 [000] 320.193156: cobalt_pthread_create: 74 02 00 00 bf 01 00 00 40 37 4b aa ab 7f 00 00 00 00 00 00 18 00 38 00 00 00 00 00 fe 7f 00 00 60 c3 24 90 ff ff ff ff 5c 81 21 90 ff ff ff ff d8 bd 8c 80 90 c1 ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
smokey-449 [000] 320.196623: cobalt_pthread_create: 74 02 00 00 c1 01 00 00 00 e7 6e a9 ab 7f 00 00 01 00 00 00 18 00 38 00 01 00 00 00 30 00 00 00 20 7c 82 77 fe 7f 00 00 60 7b 82 77 fe 7f 00 00 00 2b 89 18 55 a6 fa ba 40 37 4b aa ab 7f 00 00 3e 3d e2 00 7f 55 00 00 d0 7b 82 77 fe 7f 00 00
Regards
Hongzhan Chen
>
>Thanks,
>
>-- Steve
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [Questions][trace-cmd/libtraceevent] how to correctly parse info out from specifial format of event?
2022-01-14 1:37 ` Chen, Hongzhan
@ 2022-01-14 2:06 ` Steven Rostedt
2022-01-14 3:28 ` Chen, Hongzhan
0 siblings, 1 reply; 6+ messages in thread
From: Steven Rostedt @ 2022-01-14 2:06 UTC (permalink / raw)
To: Chen, Hongzhan; +Cc: linux-trace-devel@vger.kernel.org>, Kiszka, Kiszka, Jan
On Fri, 14 Jan 2022 01:37:08 +0000
"Chen, Hongzhan" <hongzhan.chen@intel.com> wrote:
From your other email:
> root@ecs-xenomai-isar:~# cat /sys/kernel/debug/tracing/events/cobalt_posix/cobalt_pthread_create/format
> name: cobalt_pthread_create
> ID: 628
> format:
> field:unsigned short common_type; offset:0; size:2; signed:0;
> field:unsigned char common_flags; offset:2; size:1; signed:0;
> field:unsigned char common_preempt_count; offset:3; size:1; signed:0;
> field:int common_pid; offset:4; size:4; signed:1;
>
> field:unsigned long pth; offset:8; size:8; signed:0;
> field:int policy; offset:16; size:4; signed:1;
> field:__data_loc char[] param_ex; offset:20; size:4; signed:1;
>
> print fmt: "pth=%p policy=%s param=' %s '", (void *)REC->pth, __print_symbolic(REC->policy,
> {0, "normal"}, {1, "fifo"}, {2, "rr"}, {11, "tp"}, {12, "quota"}, {10, "sporadic"}, {42, "cobalt"},
> {43, "weak"}), cobalt_trace_parse_sched_params(p, REC->policy, (struct sched_param_ex *)(__get_dynamic_array(param_ex)))
>
> [2]:
> smokey-752 [000] d.~2 7970.727466: cobalt_pthread_getschedparam: pth=000000009bbc7fe0 policy=fifo param={ priority=50 }
> smokey-762 [000] .... 7970.727492: cobalt_pthread_create: pth=00000000983468a5 policy=quota param={ priority=1, group=0 }
> Following is two dumps, please check:
>
> smokey-447 [000] 320.193156: cobalt_pthread_create: 74 02 00 00 bf 01 00 00 40 37 4b aa ab 7f 00 00 00 00 00 00 18 00 38 00 00 00 00 00 fe 7f 00 00 60 c3 24 90 ff ff ff ff 5c 81 21 90 ff ff ff ff d8 bd 8c 80 90 c1 ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
common_type: 0x0274 = 628 (matches the ID)
common_flags: 00
common_preempt_count: 00
common_pid: 0x000001bf : 447
pth: 0x00007fabaa4b3f40 (whatever that is)
policy: 0x00000000
param_ex: 0x00180038 (offset = 0x38 (56) len=0x18 (24)
Hmm, the offset points to that set of zeros at the end.
How was this event created?
> smokey-449 [000] 320.196623: cobalt_pthread_create: 74 02 00 00 c1 01 00 00 00 e7 6e a9 ab 7f 00 00 01 00 00 00 18 00 38 00 01 00 00 00 30 00 00 00 20 7c 82 77 fe 7f 00 00 60 7b 82 77 fe 7f 00 00 00 2b 89 18 55 a6 fa ba 40 37 4b aa ab 7f 00 00 3e 3d e2 00 7f 55 00 00 d0 7b 82 77 fe 7f 00 00
Although the above has content for that:
"40 37 4b aa ab 7f 00 00 3e 3d e2 00 7f 55 00 00 d0 7b 82 77 fe 7f 00 00"
-- Steve
^ permalink raw reply [flat|nested] 6+ messages in thread
* RE: [Questions][trace-cmd/libtraceevent] how to correctly parse info out from specifial format of event?
2022-01-14 2:06 ` Steven Rostedt
@ 2022-01-14 3:28 ` Chen, Hongzhan
2022-01-14 4:03 ` Steven Rostedt
0 siblings, 1 reply; 6+ messages in thread
From: Chen, Hongzhan @ 2022-01-14 3:28 UTC (permalink / raw)
To: Steven Rostedt; +Cc: linux-trace-devel@vger.kernel.org>, Kiszka, Kiszka, Jan
>-----Original Message-----
>From: Steven Rostedt <rostedt@goodmis.org>
>Sent: Friday, January 14, 2022 10:07 AM
>To: Chen, Hongzhan <hongzhan.chen@intel.com>
>Cc: linux-trace-devel@vger.kernel.org>, Kiszka <linux-trace-devel@vger.kernel.org>; Kiszka, Jan <jan.kiszka@siemens.com>
>Subject: Re: [Questions][trace-cmd/libtraceevent] how to correctly parse info out from specifial format of event?
>
>
>On Fri, 14 Jan 2022 01:37:08 +0000
>"Chen, Hongzhan" <hongzhan.chen@intel.com> wrote:
>
>From your other email:
>
>> root@ecs-xenomai-isar:~# cat /sys/kernel/debug/tracing/events/cobalt_posix/cobalt_pthread_create/format
>> name: cobalt_pthread_create
>> ID: 628
>> format:
>> field:unsigned short common_type; offset:0; size:2; signed:0;
>> field:unsigned char common_flags; offset:2; size:1; signed:0;
>> field:unsigned char common_preempt_count; offset:3; size:1; signed:0;
>> field:int common_pid; offset:4; size:4; signed:1;
>>
>> field:unsigned long pth; offset:8; size:8; signed:0;
>> field:int policy; offset:16; size:4; signed:1;
>> field:__data_loc char[] param_ex; offset:20; size:4; signed:1;
>>
>> print fmt: "pth=%p policy=%s param=' %s '", (void *)REC->pth, __print_symbolic(REC->policy,
>> {0, "normal"}, {1, "fifo"}, {2, "rr"}, {11, "tp"}, {12, "quota"}, {10, "sporadic"}, {42, "cobalt"},
>> {43, "weak"}), cobalt_trace_parse_sched_params(p, REC->policy, (struct sched_param_ex *)(__get_dynamic_array(param_ex)))
>>
>> [2]:
>> smokey-752 [000] d.~2 7970.727466: cobalt_pthread_getschedparam: pth=000000009bbc7fe0 policy=fifo param={ priority=50 }
>> smokey-762 [000] .... 7970.727492: cobalt_pthread_create: pth=00000000983468a5 policy=quota param={ priority=1, group=0 }
>
>
>
>> Following is two dumps, please check:
>>
>> smokey-447 [000] 320.193156: cobalt_pthread_create: 74 02 00 00 bf 01 00 00 40 37 4b aa ab 7f 00 00 00 00 00 00 18 00 38 00 00 00 00 00 fe 7f 00 00 60 c3 24 90 ff ff ff ff 5c 81 21 90 ff ff ff ff d8 bd 8c 80 90 c1 ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>
>common_type: 0x0274 = 628 (matches the ID)
>common_flags: 00
>common_preempt_count: 00
>common_pid: 0x000001bf : 447
>
>pth: 0x00007fabaa4b3f40 (whatever that is)
>policy: 0x00000000
>param_ex: 0x00180038 (offset = 0x38 (56) len=0x18 (24)
Thanks for your quick reply. 😊
On my X86 platform , it is printed as 0x380018(offset should be 0x18 len = 0x38). It should point to the end of field param_ex (field:__data_loc char[] param_ex; offset:20; size:4; signed:1) where store its data per my understanding. Please correct me if I am wrong.
>
>Hmm, the offset points to that set of zeros at the end.
>
>How was this event created?
The event definition please refer to https://gitlab.com/Xenomai/xenomai-hacker-space/-/blob/master/kernel/cobalt/trace/cobalt-posix.h
Regards
Hongzhan Chen
>
>> smokey-449 [000] 320.196623: cobalt_pthread_create: 74 02 00 00 c1 01 00 00 00 e7 6e a9 ab 7f 00 00 01 00 00 00 18 00 38 00 01 00 00 00 30 00 00 00 20 7c 82 77 fe 7f 00 00 60 7b 82 77 fe 7f 00 00 00 2b 89 18 55 a6 fa ba 40 37 4b aa ab 7f 00 00 3e 3d e2 00 7f 55 00 00 d0 7b 82 77 fe 7f 00 00
>
>Although the above has content for that:
>
> "40 37 4b aa ab 7f 00 00 3e 3d e2 00 7f 55 00 00 d0 7b 82 77 fe 7f 00 00"
>
>-- Steve
>
>
>
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [Questions][trace-cmd/libtraceevent] how to correctly parse info out from specifial format of event?
2022-01-14 3:28 ` Chen, Hongzhan
@ 2022-01-14 4:03 ` Steven Rostedt
2022-01-14 4:48 ` Chen, Hongzhan
0 siblings, 1 reply; 6+ messages in thread
From: Steven Rostedt @ 2022-01-14 4:03 UTC (permalink / raw)
To: Chen, Hongzhan; +Cc: linux-trace-devel@vger.kernel.org>, Kiszka, Kiszka, Jan
On Fri, 14 Jan 2022 03:28:37 +0000
"Chen, Hongzhan" <hongzhan.chen@intel.com> wrote:
> >> Following is two dumps, please check:
> >>
> >> smokey-447 [000] 320.193156: cobalt_pthread_create: 74 02 00 00 bf 01 00 00 40 37 4b aa ab 7f 00 00 00 00 00 00 18 00 38 00 00 00 00 00 fe 7f 00 00 60 c3 24 90 ff ff ff ff 5c 81 21 90 ff ff ff ff d8 bd 8c 80 90 c1 ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
> >
> >common_type: 0x0274 = 628 (matches the ID)
> >common_flags: 00
> >common_preempt_count: 00
> >common_pid: 0x000001bf : 447
> >
> >pth: 0x00007fabaa4b3f40 (whatever that is)
> >policy: 0x00000000
> >param_ex: 0x00180038 (offset = 0x38 (56) len=0x18 (24)
>
> Thanks for your quick reply. 😊
>
> On my X86 platform , it is printed as 0x380018(offset should be 0x18
> len = 0x38). It should point to the end of field param_ex
How did you get that? The above shows the 4 bytes are:
field:__data_loc char[] param_ex; offset:20; size:4; signed:1;
And if you take the 4 bytes at offset 20 from above we get:
18 00 38 00
And since this is little endian, that turns into:
0x00380018
> (field:__data_loc char[] param_ex; offset:20; size:4;
> signed:1) where store its data per my understanding. Please correct
> me if I am wrong.
>
>
> >
> >Hmm, the offset points to that set of zeros at the end.
> >
> >How was this event created?
>
> The event definition please refer to https://gitlab.com/Xenomai/xenomai-hacker-space/-/blob/master/kernel/cobalt/trace/cobalt-posix.h
>
That references other files. Are those other files taken from the Linux kernel?
Specifically:
#include <linux/tracepoint.h>
#include <linux/trace_seq.h>
#include <trace/define_trace.h>
-- Steve
^ permalink raw reply [flat|nested] 6+ messages in thread
* RE: [Questions][trace-cmd/libtraceevent] how to correctly parse info out from specifial format of event?
2022-01-14 4:03 ` Steven Rostedt
@ 2022-01-14 4:48 ` Chen, Hongzhan
0 siblings, 0 replies; 6+ messages in thread
From: Chen, Hongzhan @ 2022-01-14 4:48 UTC (permalink / raw)
To: Steven Rostedt; +Cc: linux-trace-devel@vger.kernel.org>, Kiszka, Kiszka, Jan
>
>-----Original Message-----
>From: Steven Rostedt <rostedt@goodmis.org>
>Sent: Friday, January 14, 2022 12:04 PM
>To: Chen, Hongzhan <hongzhan.chen@intel.com>
>Cc: linux-trace-devel@vger.kernel.org>, Kiszka <linux-trace-devel@vger.kernel.org>; Kiszka, Jan <jan.kiszka@siemens.com>
>Subject: Re: [Questions][trace-cmd/libtraceevent] how to correctly parse info out from specifial format of event?
>
>On Fri, 14 Jan 2022 03:28:37 +0000
>"Chen, Hongzhan" <hongzhan.chen@intel.com> wrote:
>> >> Following is two dumps, please check:
>> >>
>> >> smokey-447 [000] 320.193156: cobalt_pthread_create: 74 02 00 00 bf 01 00 00 40 37 4b aa ab 7f 00 00 00 00 00 00 18 00 38 00 00 00 00 00 fe 7f 00 00 60 c3 24 90 ff ff ff ff 5c 81 21 90 ff ff ff ff d8 bd 8c 80 90 c1 ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>> >
>> >common_type: 0x0274 = 628 (matches the ID)
>> >common_flags: 00
>> >common_preempt_count: 00
>> >common_pid: 0x000001bf : 447
>> >
>> >pth: 0x00007fabaa4b3f40 (whatever that is)
>> >policy: 0x00000000
>> >param_ex: 0x00180038 (offset = 0x38 (56) len=0x18 (24)
>>
>> Thanks for your quick reply. ??
>>
>> On my X86 platform , it is printed as 0x380018(offset should be 0x18
>> len = 0x38). It should point to the end of field param_ex
>
>How did you get that? The above shows the 4 bytes are:
>
>
> field:__data_loc char[] param_ex; offset:20; size:4; signed:1;
>
>And if you take the 4 bytes at offset 20 from above we get:
>
> 18 00 38 00
>
>And since this is little endian, that turns into:
>
> 0x00380018
>
>
>> (field:__data_loc char[] param_ex; offset:20; size:4;
>> signed:1) where store its data per my understanding. Please correct
>> me if I am wrong.
>>
>>
>
>
>> >
>> >Hmm, the offset points to that set of zeros at the end.
>> >
>> >How was this event created?
>>
>> The event definition please refer to https://gitlab.com/Xenomai/xenomai-hacker-space/-/blob/master/kernel/cobalt/trace/cobalt-posix.h
>>
>
>That references other files. Are those other files taken from the Linux kernel?
Yes, taken from Linux kernel and built together with Linux kernel.
Regards
Hongzhan Chen
>
>Specifically:
>
>#include <linux/tracepoint.h>
>#include <linux/trace_seq.h>
#include <trace/define_trace.h>
-- Steve
^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2022-01-14 4:48 UTC | newest]
Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-01-13 8:20 [Questions][trace-cmd/libtraceevent] how to correctly parse info out from specifial format of event? Chen, Hongzhan
[not found] ` <20220113140952.34d0f937@gandalf.local.home>
2022-01-14 1:37 ` Chen, Hongzhan
2022-01-14 2:06 ` Steven Rostedt
2022-01-14 3:28 ` Chen, Hongzhan
2022-01-14 4:03 ` Steven Rostedt
2022-01-14 4:48 ` Chen, Hongzhan
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.