* [lttng-dev] lttng-modules: block: invalid/unknown value for rwbs field @ 2021-03-09 13:10 Awais Belal via lttng-dev 2021-03-09 14:34 ` Francis Deslauriers via lttng-dev 0 siblings, 1 reply; 4+ messages in thread From: Awais Belal via lttng-dev @ 2021-03-09 13:10 UTC (permalink / raw) To: lttng-dev [-- Attachment #1.1: Type: text/plain, Size: 2393 bytes --] Hi, I am using lttng-modules 2.12.5 with a 5.4.93 kernel on an aarch64 target. After creating a session I run *lttng enable-event -k block** to enable all the block_ kernel events but when I run babeltrace on the generated traces I get a handful of *[warning] Unknown value 33 in enum. ... ... * with different values in place of 33. This does not happen with any other kernel event type *BabelTrace Trace Viewer and Converter 1.5.8* Also if I try to do a 'lttng view' on this session I can identify that this has something to do with the rwbs field as I get *[14:03:42.649719750] (+0.000005750) imx8qxpmek block_bio_remap: { cpu_id = 3 }, { dev = 187695200, sector = 2460080, nr_sector = 8, rwbs = ( <unknown> : container = 33 ), old_dev = 187695203, old_sector = 2105776 } [14:03:42.649722125] (+0.000002375) imx8qxpmek block_bio_queue: { cpu_id = 3 }, { dev = 187695200, sector = 2460080, nr_sector = 8, rwbs = ( <unknown> : container = 33 ), tid = 428, comm = "jbd2/mmcblk1p3-" } [14:03:42.649725000] (+0.000002875) imx8qxpmek block_bio_backmerge: { cpu_id = 3 }, { dev = 187695200, sector = 2460080, nr_sector = 8, rwbs = ( <unknown> : container = 33 ), tid = 428, comm = "jbd2/mmcblk1p3-" } ... ...* I believe <unknown> in the log points to a symptom? While for the events/container id that do not generate this warning I have in the same trace *[14:03:44.697572375] (+2.036943500) imx8qxpmek block_bio_remap: { cpu_id = 0 }, { dev = 187695200, sector = 9382032, nr_sector = 8, rwbs = ( "RWBS_FLAG_WRITE" : container = 1 ), old_dev = 187695206, old_sector = 278672 } [14:03:44.697584375] (+0.000012000) imx8qxpmek block_bio_queue: { cpu_id = 0 }, { dev = 187695200, sector = 9382032, nr_sector = 8, rwbs = ( "RWBS_FLAG_WRITE" : container = 1 ), tid = 1609, comm = "kworker/u8:0" } [14:03:44.697604250] (+0.000019875) imx8qxpmek block_getrq: { cpu_id = 0 }, { dev = 187695200, sector = 9382032, nr_sector = 8, rwbs = ( "RWBS_FLAG_WRITE" : container = 1 ), tid = 1609, comm = "kworker/u8:0" }* The interesting thing to note with the working events is that all of them have "RWBS_FLAG_WRITE" and no other types from https://github.com/lttng/lttng-modules/blob/stable-2.12/instrumentation/events/lttng-module/block.h#L39 which I would expect to see. I am lost for hints as to what I need to look up... any help would be highly appreciated. -- BR, Awais [-- Attachment #1.2: Type: text/html, Size: 3932 bytes --] [-- Attachment #2: Type: text/plain, Size: 156 bytes --] _______________________________________________ lttng-dev mailing list lttng-dev@lists.lttng.org https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev ^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [lttng-dev] lttng-modules: block: invalid/unknown value for rwbs field 2021-03-09 13:10 [lttng-dev] lttng-modules: block: invalid/unknown value for rwbs field Awais Belal via lttng-dev @ 2021-03-09 14:34 ` Francis Deslauriers via lttng-dev 2021-03-09 14:49 ` Jérémie Galarneau via lttng-dev 0 siblings, 1 reply; 4+ messages in thread From: Francis Deslauriers via lttng-dev @ 2021-03-09 14:34 UTC (permalink / raw) To: Awais Belal, lttng-dev Hi, You see this "Unknown value 33" because there are no label with the value 33 in the "block_rq_type" enumeration. More specifically, you see the value "33" because it's the result of two OR-ed bitflags (RWBS_FLAG_WRITE | RWBS_FLAG_SYNC). The type of the "rwbs" field in the event was changed from integer to enum in that commit [0]. That change was made to allow trace readers to print OR-ed values more nicely have all they need to do it. In fact, babeltrace2 implements such feature and you can try it with the following command: $ babeltrace2 -c sink.text.pretty -p print-enum-flags=true <path-to-trace> And would print that field as such: ( "RWBS_FLAG_WRITE" | "RWBS_FLAG_SYNC" : container = 33 ) I believe this feature is turn off in Babeltrace2 by default to be backward compatible with Babeltrace 1.5. It's important to note that before that change in the kernel tracer Babeltrace would have simply printed "rwbs = 33" so you're not losing any information here. So, try it out with Babeltrace2, it should work as you expect. Cheers, Francis [0] https://github.com/lttng/lttng-modules/commit/23634515e7271c8c8594ad87a6685232d4eff297 On 3/9/21 8:10 AM, Awais Belal via lttng-dev wrote: > > Hi, > > I am using lttng-modules 2.12.5 with a 5.4.93 kernel on an aarch64 > target. After creating a session I run > > *lttng enable-event -k block** > > to enable all the block_ kernel events but when I run babeltrace on > the generated traces I get a handful of > > *[warning] Unknown value 33 in enum. > ... > ... > * > > with different values in place of 33. This does not happen with any > other kernel event type > > *BabelTrace Trace Viewer and Converter 1.5.8* > > Also if I try to do a 'lttng view' on this session I can identify that > this has something to do with the rwbs field as I get > > *[14:03:42.649719750] (+0.000005750) imx8qxpmek block_bio_remap: { > cpu_id = 3 }, { dev = 187695200, sector = 2460080, nr_sector = 8, rwbs > = ( <unknown> : container = 33 ), old_dev = 187695203, old_sector = > 2105776 } > [14:03:42.649722125] (+0.000002375) imx8qxpmek block_bio_queue: { > cpu_id = 3 }, { dev = 187695200, sector = 2460080, nr_sector = 8, rwbs > = ( <unknown> : container = 33 ), tid = 428, comm = "jbd2/mmcblk1p3-" } > [14:03:42.649725000] (+0.000002875) imx8qxpmek block_bio_backmerge: { > cpu_id = 3 }, { dev = 187695200, sector = 2460080, nr_sector = 8, rwbs > = ( <unknown> : container = 33 ), tid = 428, comm = "jbd2/mmcblk1p3-" } > ... > ...* > > I believe <unknown> in the log points to a symptom? While for the > events/container id that do not generate this warning I have in the > same trace > > *[14:03:44.697572375] (+2.036943500) imx8qxpmek block_bio_remap: { > cpu_id = 0 }, { dev = 187695200, sector = 9382032, nr_sector = 8, rwbs > = ( "RWBS_FLAG_WRITE" : container = 1 ), old_dev = 187695206, > old_sector = 278672 } > [14:03:44.697584375] (+0.000012000) imx8qxpmek block_bio_queue: { > cpu_id = 0 }, { dev = 187695200, sector = 9382032, nr_sector = 8, rwbs > = ( "RWBS_FLAG_WRITE" : container = 1 ), tid = 1609, comm = > "kworker/u8:0" } > [14:03:44.697604250] (+0.000019875) imx8qxpmek block_getrq: { cpu_id = > 0 }, { dev = 187695200, sector = 9382032, nr_sector = 8, rwbs = ( > "RWBS_FLAG_WRITE" : container = 1 ), tid = 1609, comm = "kworker/u8:0" }* > > The interesting thing to note with the working events is that all of > them have "RWBS_FLAG_WRITE" and no other types from > https://github.com/lttng/lttng-modules/blob/stable-2.12/instrumentation/events/lttng-module/block.h#L39 > which I would expect to see. > > I am lost for hints as to what I need to look up... any help would be > highly appreciated. > > -- > BR, > Awais > > _______________________________________________ > lttng-dev mailing list > lttng-dev@lists.lttng.org > https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev _______________________________________________ lttng-dev mailing list lttng-dev@lists.lttng.org https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev ^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [lttng-dev] lttng-modules: block: invalid/unknown value for rwbs field 2021-03-09 14:34 ` Francis Deslauriers via lttng-dev @ 2021-03-09 14:49 ` Jérémie Galarneau via lttng-dev 2021-03-09 15:11 ` Awais Belal via lttng-dev 0 siblings, 1 reply; 4+ messages in thread From: Jérémie Galarneau via lttng-dev @ 2021-03-09 14:49 UTC (permalink / raw) To: Francis Deslauriers; +Cc: Awais Belal, lttng-dev Just adding to Francis' explanation (and following up on Awais' questions on IRC): the reason the `print-enum-flags` option is not the default is found here [1]. tl;dr: bitwise enumerations are not defined in CTF 1.8 and will likely be part of CTF 2.0. Also, this option is only available in master for the moment and will be part of a future 2.1 release. Thanks, Jérémie [1] https://review.lttng.org/c/babeltrace/+/3045/31#message-c7709b4431ad720962fe9b80880bc689f294c4a9 ----- Original Message ----- From: "lttng-dev" <lttng-dev@lists.lttng.org> To: "Awais Belal" <awais_belal@mentor.com>, "lttng-dev" <lttng-dev@lists.lttng.org> Sent: Tuesday, March 9, 2021 9:34:09 AM Subject: Re: [lttng-dev] lttng-modules: block: invalid/unknown value for rwbs field Hi, You see this "Unknown value 33" because there are no label with the value 33 in the "block_rq_type" enumeration. More specifically, you see the value "33" because it's the result of two OR-ed bitflags (RWBS_FLAG_WRITE | RWBS_FLAG_SYNC). The type of the "rwbs" field in the event was changed from integer to enum in that commit [0]. That change was made to allow trace readers to print OR-ed values more nicely have all they need to do it. In fact, babeltrace2 implements such feature and you can try it with the following command: $ babeltrace2 -c sink.text.pretty -p print-enum-flags=true <path-to-trace> And would print that field as such: ( "RWBS_FLAG_WRITE" | "RWBS_FLAG_SYNC" : container = 33 ) I believe this feature is turn off in Babeltrace2 by default to be backward compatible with Babeltrace 1.5. It's important to note that before that change in the kernel tracer Babeltrace would have simply printed "rwbs = 33" so you're not losing any information here. So, try it out with Babeltrace2, it should work as you expect. Cheers, Francis [0] https://github.com/lttng/lttng-modules/commit/23634515e7271c8c8594ad87a6685232d4eff297 On 3/9/21 8:10 AM, Awais Belal via lttng-dev wrote: > > Hi, > > I am using lttng-modules 2.12.5 with a 5.4.93 kernel on an aarch64 > target. After creating a session I run > > *lttng enable-event -k block** > > to enable all the block_ kernel events but when I run babeltrace on > the generated traces I get a handful of > > *[warning] Unknown value 33 in enum. > ... > ... > * > > with different values in place of 33. This does not happen with any > other kernel event type > > *BabelTrace Trace Viewer and Converter 1.5.8* > > Also if I try to do a 'lttng view' on this session I can identify that > this has something to do with the rwbs field as I get > > *[14:03:42.649719750] (+0.000005750) imx8qxpmek block_bio_remap: { > cpu_id = 3 }, { dev = 187695200, sector = 2460080, nr_sector = 8, rwbs > = ( <unknown> : container = 33 ), old_dev = 187695203, old_sector = > 2105776 } > [14:03:42.649722125] (+0.000002375) imx8qxpmek block_bio_queue: { > cpu_id = 3 }, { dev = 187695200, sector = 2460080, nr_sector = 8, rwbs > = ( <unknown> : container = 33 ), tid = 428, comm = "jbd2/mmcblk1p3-" } > [14:03:42.649725000] (+0.000002875) imx8qxpmek block_bio_backmerge: { > cpu_id = 3 }, { dev = 187695200, sector = 2460080, nr_sector = 8, rwbs > = ( <unknown> : container = 33 ), tid = 428, comm = "jbd2/mmcblk1p3-" } > ... > ...* > > I believe <unknown> in the log points to a symptom? While for the > events/container id that do not generate this warning I have in the > same trace > > *[14:03:44.697572375] (+2.036943500) imx8qxpmek block_bio_remap: { > cpu_id = 0 }, { dev = 187695200, sector = 9382032, nr_sector = 8, rwbs > = ( "RWBS_FLAG_WRITE" : container = 1 ), old_dev = 187695206, > old_sector = 278672 } > [14:03:44.697584375] (+0.000012000) imx8qxpmek block_bio_queue: { > cpu_id = 0 }, { dev = 187695200, sector = 9382032, nr_sector = 8, rwbs > = ( "RWBS_FLAG_WRITE" : container = 1 ), tid = 1609, comm = > "kworker/u8:0" } > [14:03:44.697604250] (+0.000019875) imx8qxpmek block_getrq: { cpu_id = > 0 }, { dev = 187695200, sector = 9382032, nr_sector = 8, rwbs = ( > "RWBS_FLAG_WRITE" : container = 1 ), tid = 1609, comm = "kworker/u8:0" }* > > The interesting thing to note with the working events is that all of > them have "RWBS_FLAG_WRITE" and no other types from > https://github.com/lttng/lttng-modules/blob/stable-2.12/instrumentation/events/lttng-module/block.h#L39 > which I would expect to see. > > I am lost for hints as to what I need to look up... any help would be > highly appreciated. > > -- > BR, > Awais > > _______________________________________________ > lttng-dev mailing list > lttng-dev@lists.lttng.org > https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev _______________________________________________ lttng-dev mailing list lttng-dev@lists.lttng.org https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev _______________________________________________ lttng-dev mailing list lttng-dev@lists.lttng.org https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev ^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [lttng-dev] lttng-modules: block: invalid/unknown value for rwbs field 2021-03-09 14:49 ` Jérémie Galarneau via lttng-dev @ 2021-03-09 15:11 ` Awais Belal via lttng-dev 0 siblings, 0 replies; 4+ messages in thread From: Awais Belal via lttng-dev @ 2021-03-09 15:11 UTC (permalink / raw) To: Jérémie Galarneau, Francis Deslauriers; +Cc: lttng-dev > So, try it out with Babeltrace2, it should work as you expect. Thanks a lot guys, bt2 works as expected. BR, Awais On 09/03/2021 19:49, Jérémie Galarneau wrote: > Just adding to Francis' explanation (and following up on Awais' questions on IRC): > the reason the `print-enum-flags` option is not the default is found here [1]. > > tl;dr: bitwise enumerations are not defined in CTF 1.8 and will likely be > part of CTF 2.0. > > Also, this option is only available in master for the moment and will be part > of a future 2.1 release. > > Thanks, > Jérémie > > [1] https://review.lttng.org/c/babeltrace/+/3045/31#message-c7709b4431ad720962fe9b80880bc689f294c4a9 > > ----- Original Message ----- > From: "lttng-dev" <lttng-dev@lists.lttng.org> > To: "Awais Belal" <awais_belal@mentor.com>, "lttng-dev" <lttng-dev@lists.lttng.org> > Sent: Tuesday, March 9, 2021 9:34:09 AM > Subject: Re: [lttng-dev] lttng-modules: block: invalid/unknown value for rwbs field > > Hi, > > You see this "Unknown value 33" because there are no label with the > value 33 in the "block_rq_type" enumeration. > > More specifically, you see the value "33" because it's the result of two > OR-ed bitflags (RWBS_FLAG_WRITE | RWBS_FLAG_SYNC). > > The type of the "rwbs" field in the event was changed from integer to > enum in that commit [0]. That change was made to allow trace readers to > print OR-ed values more nicely have all they need to do it. In fact, > babeltrace2 implements such feature and you can try it with the > following command: > > $ babeltrace2 -c sink.text.pretty -p print-enum-flags=true <path-to-trace> > > And would print that field as such: ( "RWBS_FLAG_WRITE" | > "RWBS_FLAG_SYNC" : container = 33 ) > > I believe this feature is turn off in Babeltrace2 by default to be > backward compatible with Babeltrace 1.5. > > It's important to note that before that change in the kernel tracer > Babeltrace would have simply printed "rwbs = 33" so you're not losing > any information here. > > So, try it out with Babeltrace2, it should work as you expect. > > > Cheers, > > Francis > > [0] > https://github.com/lttng/lttng-modules/commit/23634515e7271c8c8594ad87a6685232d4eff297 > > > On 3/9/21 8:10 AM, Awais Belal via lttng-dev wrote: >> Hi, >> >> I am using lttng-modules 2.12.5 with a 5.4.93 kernel on an aarch64 >> target. After creating a session I run >> >> *lttng enable-event -k block** >> >> to enable all the block_ kernel events but when I run babeltrace on >> the generated traces I get a handful of >> >> *[warning] Unknown value 33 in enum. >> ... >> ... >> * >> >> with different values in place of 33. This does not happen with any >> other kernel event type >> >> *BabelTrace Trace Viewer and Converter 1.5.8* >> >> Also if I try to do a 'lttng view' on this session I can identify that >> this has something to do with the rwbs field as I get >> >> *[14:03:42.649719750] (+0.000005750) imx8qxpmek block_bio_remap: { >> cpu_id = 3 }, { dev = 187695200, sector = 2460080, nr_sector = 8, rwbs >> = ( <unknown> : container = 33 ), old_dev = 187695203, old_sector = >> 2105776 } >> [14:03:42.649722125] (+0.000002375) imx8qxpmek block_bio_queue: { >> cpu_id = 3 }, { dev = 187695200, sector = 2460080, nr_sector = 8, rwbs >> = ( <unknown> : container = 33 ), tid = 428, comm = "jbd2/mmcblk1p3-" } >> [14:03:42.649725000] (+0.000002875) imx8qxpmek block_bio_backmerge: { >> cpu_id = 3 }, { dev = 187695200, sector = 2460080, nr_sector = 8, rwbs >> = ( <unknown> : container = 33 ), tid = 428, comm = "jbd2/mmcblk1p3-" } >> ... >> ...* >> >> I believe <unknown> in the log points to a symptom? While for the >> events/container id that do not generate this warning I have in the >> same trace >> >> *[14:03:44.697572375] (+2.036943500) imx8qxpmek block_bio_remap: { >> cpu_id = 0 }, { dev = 187695200, sector = 9382032, nr_sector = 8, rwbs >> = ( "RWBS_FLAG_WRITE" : container = 1 ), old_dev = 187695206, >> old_sector = 278672 } >> [14:03:44.697584375] (+0.000012000) imx8qxpmek block_bio_queue: { >> cpu_id = 0 }, { dev = 187695200, sector = 9382032, nr_sector = 8, rwbs >> = ( "RWBS_FLAG_WRITE" : container = 1 ), tid = 1609, comm = >> "kworker/u8:0" } >> [14:03:44.697604250] (+0.000019875) imx8qxpmek block_getrq: { cpu_id = >> 0 }, { dev = 187695200, sector = 9382032, nr_sector = 8, rwbs = ( >> "RWBS_FLAG_WRITE" : container = 1 ), tid = 1609, comm = "kworker/u8:0" }* >> >> The interesting thing to note with the working events is that all of >> them have "RWBS_FLAG_WRITE" and no other types from >> https://github.com/lttng/lttng-modules/blob/stable-2.12/instrumentation/events/lttng-module/block.h#L39 >> which I would expect to see. >> >> I am lost for hints as to what I need to look up... any help would be >> highly appreciated. >> >> -- >> BR, >> Awais >> >> _______________________________________________ >> lttng-dev mailing list >> lttng-dev@lists.lttng.org >> https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev > _______________________________________________ > lttng-dev mailing list > lttng-dev@lists.lttng.org > https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev _______________________________________________ lttng-dev mailing list lttng-dev@lists.lttng.org https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev ^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2021-03-09 15:11 UTC | newest] Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2021-03-09 13:10 [lttng-dev] lttng-modules: block: invalid/unknown value for rwbs field Awais Belal via lttng-dev 2021-03-09 14:34 ` Francis Deslauriers via lttng-dev 2021-03-09 14:49 ` Jérémie Galarneau via lttng-dev 2021-03-09 15:11 ` Awais Belal via lttng-dev
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).