On 21 Sep 2022, at 11:17, Eelco Chaudron wrote:
> On 20 Sep 2022, at 20:52, Aaron Conole wrote: > >> Eelco Chaudron <[email protected]> writes: >> >>> This patch adds a Python script that can be used to analyze the >>> revalidator runs by providing statistics (including some real time >>> graphs). >>> >>> The USDT events can also be captured to a file and used for >>> later offline analysis. >>> >>> Signed-off-by: Eelco Chaudron <[email protected]> >>> --- >> >> Some of this work looks to be covered by the patch at >> https://lists.linuxfoundation.org/pipermail/ovs-dev/2022-July/396545.html >> >> Maybe we should fold some of them together, since there seems to be some >> overlap. > > I looked at this before, and both scripts cover a different use case, and the > USDT probes could not be re-used. The only thing that could be re-used is the > ovs_struct.h file :) > > My suggestion would be to keep both patches separated, as combining them > would probably result in a series of two individual patches. > >>> v2: Added note that script only works a with single datapath configured. >>> >>> I'm planning a blog post to explain the Open vSwitch revalidator >>> implementation, and this tool will help you determine what is >>> happening in your system. Also, here is a link to an example >>> of a real-time and overall plot. >>> >>> https://photos.app.goo.gl/rdx63zuFure7QE3t6 >>> >>> Documentation/topics/usdt-probes.rst | 84 +++ >>> ofproto/ofproto-dpif-upcall.c | 11 >>> utilities/automake.mk | 4 >>> utilities/usdt-scripts/ovs_structs.h | 123 +++++ >>> utilities/usdt-scripts/reval_monitor.py | 758 >>> +++++++++++++++++++++++++++++++ >>> 5 files changed, 979 insertions(+), 1 deletion(-) >>> create mode 100644 utilities/usdt-scripts/ovs_structs.h >>> create mode 100755 utilities/usdt-scripts/reval_monitor.py >>> >>> diff --git a/Documentation/topics/usdt-probes.rst >>> b/Documentation/topics/usdt-probes.rst >>> index 7ce19aaed..bc250e723 100644 >>> --- a/Documentation/topics/usdt-probes.rst >>> +++ b/Documentation/topics/usdt-probes.rst >>> @@ -214,6 +214,10 @@ Available probes in ``ovs_vswitchd``: >>> - dpif_recv:recv_upcall >>> - main:poll_block >>> - main:run_start >>> +- revalidate_ukey\_\_:entry >>> +- revalidate_ukey\_\_:exit >>> +- udpif_revalidator:start_dump >>> +- udpif_revalidator:sweep_done >>> >>> >>> dpif_netlink_operate\_\_:op_flow_del >>> @@ -327,6 +331,7 @@ probe main:run_start >>> ~~~~~~~~~~~~~~~~~~~~ >>> >>> **Description**: >>> + >>> The ovs-vswitchd's main process contains a loop that runs every time some >>> work >>> needs to be done. This probe gets triggered every time the loop starts >>> from the >>> beginning. See also the ``main:poll_block`` probe below. >>> @@ -344,6 +349,7 @@ probe main:poll_block >>> ~~~~~~~~~~~~~~~~~~~~~ >>> >>> **Description**: >>> + >>> The ovs-vswitchd's main process contains a loop that runs every time some >>> work >>> needs to be done. This probe gets triggered every time the loop is done, >>> and >>> it's about to wait for being re-started by a poll_block() call returning. >>> @@ -358,6 +364,84 @@ See also the ``main:run_start`` probe above. >>> - ``utilities/usdt-scripts/bridge_loop.bt`` >>> >>> >>> +revalidate_ukey\_\_:entry >>> +~~~~~~~~~~~~~~~~~~~~~~~~~ >>> + >>> +**Description**: >>> + >>> +This probe gets triggered on entry of the revalidate_ukey__() function. >>> + >>> +**Arguments**: >>> + >>> +- *arg0*: ``(struct udpif *) udpif`` >>> +- *arg1*: ``(struct udpif_key *) ukey`` >>> +- *arg2*: ``(uint16_t) tcp_flags`` >>> +- *arg3*: ``(struct ofpbuf *) odp_actions`` >>> +- *arg4*: ``(struct recirc_refs *) recircs`` >>> +- *arg5*: ``(struct xlate_cache *) xcache`` >>> + >>> +**Script references**: >>> + >>> +- ``utilities/usdt-scripts/reval_monitor.py`` >>> + >>> + >>> +revalidate_ukey\_\_:exit >>> +~~~~~~~~~~~~~~~~~~~~~~~~ >>> + >>> +**Description**: >>> + >>> +This probe gets triggered right before the revalidate_ukey__() function >>> exits. >>> + >>> +**Arguments**: >>> + >>> +- *arg0*: ``(struct udpif *) udpif`` >>> +- *arg1*: ``(struct udpif_key *) ukey`` >>> +- *arg2*: ``(enum reval_result) result`` >>> + >>> +**Script references**: >>> + >>> +*None* >> >> Is it a good idea to add something that isn't referenced? > > I think it is. To be honest, we should add way more USDT probes in OVS that > can be used by a developer to debug specific issues. > >> For example, >> your scripts are meant to help understand what happens during >> revalidation. This symbol isn't referenced in your script, and it makes >> me think that it isn't particularly useful. > > The purpose of these scripts is for the end-user to get some insight into the > system. But the more important reason for adding the script is that a > developer has a framework he can quickly modify to debug specific issues. > > This probe, for example, can be used to measure the cumulative time spent > doing revalidation. I had this added to the script, but it caused some > confusion, which for end-users we should avoid. > >>> +udpif_revalidator:start_dump >>> +~~~~~~~~~~~~~~~~~~~~~~~~~~~~ >>> + >>> +**Description**: >>> + >>> +The ovs-vswitchd's revalidator process contains a loop that runs every time >>> +revalidation work is needed. This probe gets triggered every time the >>> +dump phase has started. >>> + >>> +**Arguments**: >>> + >>> +- *arg0*: ``(struct udpif *) udpif`` >>> +- *arg1*: ``(size_t) n_flows`` >>> + >>> +**Script references**: >>> + >>> +- ``utilities/usdt-scripts/reval_monitor.py`` >>> + >>> + >>> +udpif_revalidator:sweep_done >>> +~~~~~~~~~~~~~~~~~~~~~~~~~~~~ >>> + >>> +**Description**: >>> + >>> +The ovs-vswitchd's revalidator process contains a loop that runs every time >>> +revalidation work is needed. This probe gets triggered every time the >>> +sweep phase was completed. >>> + >>> +**Arguments**: >>> + >>> +- *arg0*: ``(struct udpif *) udpif`` >>> +- *arg1*: ``(size_t) n_flows`` >>> +- *arg2*: ``(unsigned) MIN(ofproto_max_idle, ofproto_max_revalidator)`` >>> + >>> +**Script references**: >>> + >>> +- ``utilities/usdt-scripts/reval_monitor.py`` >>> + >>> + >>> Adding your own probes >>> ---------------------- >>> >>> diff --git a/ofproto/ofproto-dpif-upcall.c b/ofproto/ofproto-dpif-upcall.c >>> index 57f94df54..4c016ee34 100644 >>> --- a/ofproto/ofproto-dpif-upcall.c >>> +++ b/ofproto/ofproto-dpif-upcall.c >>> @@ -42,6 +42,7 @@ >>> #include "seq.h" >>> #include "tunnel.h" >>> #include "unixctl.h" >>> +#include "openvswitch/usdt-probes.h" >>> #include "openvswitch/vlog.h" >>> #include "lib/netdev-provider.h" >>> >>> @@ -965,6 +966,7 @@ udpif_revalidator(void *arg) >>> terse_dump = udpif_use_ufid(udpif); >>> udpif->dump = dpif_flow_dump_create(udpif->dpif, >>> terse_dump, >>> NULL); >>> + OVS_USDT_PROBE(udpif_revalidator, start_dump, udpif, >>> n_flows); >>> } >>> } >>> >>> @@ -1016,6 +1018,9 @@ udpif_revalidator(void *arg) >>> duration); >>> } >>> >>> + OVS_USDT_PROBE(udpif_revalidator, sweep_done, udpif, n_flows, >>> + MIN(ofproto_max_idle, ofproto_max_revalidator)); >>> + >>> poll_timer_wait_until(start_time + MIN(ofproto_max_idle, >>> >>> ofproto_max_revalidator)); >>> seq_wait(udpif->reval_seq, last_reval_seq); >>> @@ -2215,6 +2220,9 @@ revalidate_ukey__(struct udpif *udpif, const struct >>> udpif_key *ukey, >>> .wc = &wc, >>> }; >>> >>> + OVS_USDT_PROBE(revalidate_ukey__, entry, udpif, ukey, tcp_flags, >>> + odp_actions, recircs, xcache); >>> + >>> result = UKEY_DELETE; >>> xoutp = NULL; >>> netflow = NULL; >>> @@ -2278,6 +2286,9 @@ exit: >>> netflow_flow_clear(netflow, &ctx.flow); >>> } >>> xlate_out_uninit(xoutp); >>> + >>> + OVS_USDT_PROBE(revalidate_ukey__, exit, udpif, ukey, result); >>> + >>> return result; >>> } >>> >>> diff --git a/utilities/automake.mk b/utilities/automake.mk >>> index eb57653a1..e0d5a6c00 100644 >>> --- a/utilities/automake.mk >>> +++ b/utilities/automake.mk >>> @@ -63,8 +63,10 @@ EXTRA_DIST += \ >>> utilities/docker/debian/Dockerfile \ >>> utilities/docker/debian/build-kernel-modules.sh \ >>> utilities/usdt-scripts/bridge_loop.bt \ >>> + utilities/usdt-scripts/ovs_structs.h \ >>> utilities/usdt-scripts/upcall_cost.py \ >>> - utilities/usdt-scripts/upcall_monitor.py >>> + utilities/usdt-scripts/upcall_monitor.py \ >>> + utilities/usdt-scripts/reval_monitor.py >>> MAN_ROOTS += \ >>> utilities/ovs-testcontroller.8.in \ >>> utilities/ovs-dpctl.8.in \ >>> diff --git a/utilities/usdt-scripts/ovs_structs.h >>> b/utilities/usdt-scripts/ovs_structs.h >>> new file mode 100644 >>> index 000000000..9fa2bf599 >>> --- /dev/null >>> +++ b/utilities/usdt-scripts/ovs_structs.h >> >> I'm not a fan of this. Any updates to these structs needs to be >> mirrored across the codebase. I think it might be better to do >> something else. > > I agree with this, but for keeping things simple and not replicating this in > all scripts (see the previous patch you mentioned). I thought it would be > easier to have it in a single file. > >> For example, maybe we can use a pyelf extension to >> probe for the actual struct info if compiled with '-g' - something like >> that. Or, perhaps we can use a stringify-ing macro and cli command that >> will print a lite header that we can include. Otherwise, this is two >> areas struct info needs to be maintained, and it will get out of sync. >> Heck, even auto-generating it after the build with GDB is something that >> I would prefer to hardcoding (something like ptype <struct ...>, which >> does require compiling with '-g'). > > All this sounds nice, but is not something that is easily added. Think about > structure references, inclusion, and recursion. I know Adrian is researching > this for another project, so we might get this in the near future :) Now with Adrian added in CC... > To move both patches forward, we could either keep the ovs_struct.h file, or > embed it in the individual scripts. I’m fine with both and will try to keep > them in sync until we can integrate Adrian’s solution. > > <SNIP> _______________________________________________ dev mailing list [email protected] https://mail.openvswitch.org/mailman/listinfo/ovs-dev
