Re: [PATCH 4/4] net/colo: Match is-enabled probe to tracepoint

["Daniel P. Berrangé" <berrange@redhat.com>]

Adding Stefan to CC as the trace maintainer.

On Thu, Jul 16, 2020 at 11:17:54AM +0300, Roman Bolshakov wrote:
> Build of QEMU with dtrace fails on macOS:
> 
>   LINK    x86_64-softmmu/qemu-system-x86_64
> error: probe colo_compare_miscompare doesn't exist
> error: Could not register probes
> ld: error creating dtrace DOF section for architecture x86_64
> 
> The reason of the error is explained by Adam Leventhal [1]:
> 
>   Note that is-enabled probes don't have the stability magic so I'm not
>   sure how things would work if only is-enabled probes were used.
> 
> net/colo code uses is-enabled probes to determine if other probes should
> be used but colo_compare_miscompare itself is not used explicitly.
> Linker doesn't include the symbol and build fails.
> 
> The issue can be resolved if is-enabled probe matches the actual trace
> point that is used inside the test.
> 
> 1. http://markmail.org/message/6grq2ygr5nwdwsnb
> 
> Fixes: f4b618360e ("colo-compare: add TCP, UDP, ICMP packet comparison")
> Cc: Philippe Mathieu-Daudé <philmd@redhat.com>
> Cc: Cameron Esfahani <dirty@apple.com>
> Signed-off-by: Roman Bolshakov <r.bolshakov@yadro.com>
> ---
>  net/colo-compare.c    | 12 +++++++-----
>  net/filter-rewriter.c |  8 ++++++--
>  net/trace-events      |  2 --
>  3 files changed, 13 insertions(+), 9 deletions(-)
> 
> diff --git a/net/colo-compare.c b/net/colo-compare.c
> index 398b7546ff..9525ed703b 100644
> --- a/net/colo-compare.c
> +++ b/net/colo-compare.c
> @@ -327,7 +327,7 @@ static int colo_compare_packet_payload(Packet *ppkt,
>                                         uint16_t len)
>  
>  {
> -    if (trace_event_get_state_backends(TRACE_COLO_COMPARE_MISCOMPARE)) {
> +    if (trace_event_get_state_backends(TRACE_COLO_COMPARE_IP_INFO)) {
>          char pri_ip_src[20], pri_ip_dst[20], sec_ip_src[20], sec_ip_dst[20];
>  
>          strcpy(pri_ip_src, inet_ntoa(ppkt->ip->ip_src));
> @@ -492,7 +492,7 @@ sec:
>          g_queue_push_head(&conn->primary_list, ppkt);
>          g_queue_push_head(&conn->secondary_list, spkt);
>  
> -        if (trace_event_get_state_backends(TRACE_COLO_COMPARE_MISCOMPARE)) {
> +        if (trace_event_get_state_backends(TRACE_COLO_COMPARE_TCP_INFO)) {
>              qemu_hexdump((char *)ppkt->data, stderr,
>                          "colo-compare ppkt", ppkt->size);
>              qemu_hexdump((char *)spkt->data, stderr,

Not your fault, as this problem is pre-existing, but IMHO this block of code
is simply broken by design. It is checking a trace event enablement state,
and then not emitting any trace event, but instead dumping info to stderr.
This is mis-use of the trace framework, and changing the event name fixes
your immediate macOS bug but the code is still flawed.

Basically it is using the trace framework as a way to dynamically turn on /
off general debugging information.

I'm not quite sure what todo to fix it, but I don't think it should be wrapped
in any trace_event_get_state_backends() call at all.

The simplest immediate option I think is to change it to be a compile time
debug

  // #define DEBUG_COLO_PACKETS

and then use

  #ifdef DEBUG_COLO_PACKETS
      qemu_hexdump(...)
  #endif

and then leave it upto the maintainer to come up with a more advanced
solution if they want to make it runtime configurable again, but not
abusing the trace framework.

> @@ -533,7 +533,8 @@ static int colo_packet_compare_udp(Packet *spkt, Packet *ppkt)
>                                      ppkt->size - offset)) {
>          trace_colo_compare_udp_miscompare("primary pkt size", ppkt->size);
>          trace_colo_compare_udp_miscompare("Secondary pkt size", spkt->size);
> -        if (trace_event_get_state_backends(TRACE_COLO_COMPARE_MISCOMPARE)) {
> +        if (trace_event_get_state_backends(
> +              TRACE_COLO_COMPARE_UDP_MISCOMPARE)) {
>              qemu_hexdump((char *)ppkt->data, stderr, "colo-compare pri pkt",
>                           ppkt->size);
>              qemu_hexdump((char *)spkt->data, stderr, "colo-compare sec pkt",

Same brokenness

> @@ -576,7 +577,8 @@ static int colo_packet_compare_icmp(Packet *spkt, Packet *ppkt)
>                                             ppkt->size);
>          trace_colo_compare_icmp_miscompare("Secondary pkt size",
>                                             spkt->size);
> -        if (trace_event_get_state_backends(TRACE_COLO_COMPARE_MISCOMPARE)) {
> +        if (trace_event_get_state_backends(
> +              TRACE_COLO_COMPARE_ICMP_MISCOMPARE)) {
>              qemu_hexdump((char *)ppkt->data, stderr, "colo-compare pri pkt",
>                           ppkt->size);
>              qemu_hexdump((char *)spkt->data, stderr, "colo-compare sec pkt",

Same brokenness

> @@ -597,7 +599,7 @@ static int colo_packet_compare_other(Packet *spkt, Packet *ppkt)
>      uint16_t offset = ppkt->vnet_hdr_len;
>  
>      trace_colo_compare_main("compare other");
> -    if (trace_event_get_state_backends(TRACE_COLO_COMPARE_MISCOMPARE)) {
> +    if (trace_event_get_state_backends(TRACE_COLO_COMPARE_IP_INFO)) {
>          char pri_ip_src[20], pri_ip_dst[20], sec_ip_src[20], sec_ip_dst[20];
>  
>          strcpy(pri_ip_src, inet_ntoa(ppkt->ip->ip_src));
> diff --git a/net/filter-rewriter.c b/net/filter-rewriter.c
> index 1aaad101b6..ff04165cc4 100644
> --- a/net/filter-rewriter.c
> +++ b/net/filter-rewriter.c
> @@ -76,7 +76,9 @@ static int handle_primary_tcp_pkt(RewriterState *rf,
>      struct tcp_hdr *tcp_pkt;
>  
>      tcp_pkt = (struct tcp_hdr *)pkt->transport_header;
> -    if (trace_event_get_state_backends(TRACE_COLO_FILTER_REWRITER_DEBUG)) {
> +    if (trace_event_get_state_backends(TRACE_COLO_FILTER_REWRITER_PKT_INFO) ||
> +        trace_event_get_state_backends(
> +          TRACE_COLO_FILTER_REWRITER_CONN_OFFSET)) {
>          trace_colo_filter_rewriter_pkt_info(__func__,
>                      inet_ntoa(pkt->ip->ip_src), inet_ntoa(pkt->ip->ip_dst),
>                      ntohl(tcp_pkt->th_seq), ntohl(tcp_pkt->th_ack),

Since there are two separate trace events here, each should be wrapped with
its own check. IOW, two completely separate if (...) trace(..); blocks

> @@ -180,7 +182,9 @@ static int handle_secondary_tcp_pkt(RewriterState *rf,
>  
>      tcp_pkt = (struct tcp_hdr *)pkt->transport_header;
>  
> -    if (trace_event_get_state_backends(TRACE_COLO_FILTER_REWRITER_DEBUG)) {
> +    if (trace_event_get_state_backends(TRACE_COLO_FILTER_REWRITER_PKT_INFO) ||
> +        trace_event_get_state_backends(
> +          TRACE_COLO_FILTER_REWRITER_CONN_OFFSET)) {
>          trace_colo_filter_rewriter_pkt_info(__func__,
>                      inet_ntoa(pkt->ip->ip_src), inet_ntoa(pkt->ip->ip_dst),
>                      ntohl(tcp_pkt->th_seq), ntohl(tcp_pkt->th_ack),

Same here.


Regards,
Daniel
-- 
|: https://berrange.com      -o-    https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org         -o-            https://fstop138.berrange.com :|
|: https://entangle-photo.org    -o-    https://www.instagram.com/dberrange :|