diff mbox series

[ovs-dev] ofproto-dpif-upcall: Print more data on unassociated datapath ports.

Message ID 20220901154249.3929098-1-i.maximets@ovn.org
State Accepted
Commit 96b26dce1da18f00dcad2e14bc058158fffa313f
Headers show
Series [ovs-dev] ofproto-dpif-upcall: Print more data on unassociated datapath ports. | expand

Checks

Context Check Description
ovsrobot/apply-robot success apply and check: success
ovsrobot/github-robot-_Build_and_Test success github build: passed
ovsrobot/intel-ovs-compilation success test: success

Commit Message

Ilya Maximets Sept. 1, 2022, 3:42 p.m. UTC
When OVS fails to find an OpenFlow port for a packet received
from the upcall it just prints the warning like this:

  |INFO|received packet on unassociated datapath port N

However, during the flow translation more information is available
as if the recirculation id wasn't found or it was a packet from
unknown tunnel port.  Printing that information might be useful
to understand the origin of the problem.

Port translation functions already support extended error strings,
we just need to pass a variable where to store them.

With the change the output may be:

  |INFO|received packet on unassociated datapath port N
        (no OpenFlow port for datapath port N)
or
  |INFO|received packet on unassociated datapath port N
        (no OpenFlow tunnel port for this packet)
or
  |INFO|received packet on unassociated datapath port N
        (no recirculation data for recirc_id M)

Unfortunately, there is no good way to trigger this code from
current unit tests.

Signed-off-by: Ilya Maximets <i.maximets@ovn.org>
---
 ofproto/ofproto-dpif-upcall.c | 27 +++++++++++++++++++--------
 ofproto/ofproto-dpif-xlate.c  |  6 ++++--
 ofproto/ofproto-dpif-xlate.h  |  2 +-
 3 files changed, 24 insertions(+), 11 deletions(-)

Comments

Mike Pattrick Sept. 29, 2022, 4:40 p.m. UTC | #1
On Thu, Sep 1, 2022 at 11:43 AM Ilya Maximets <i.maximets@ovn.org> wrote:
>
> When OVS fails to find an OpenFlow port for a packet received
> from the upcall it just prints the warning like this:
>
>   |INFO|received packet on unassociated datapath port N
>
> However, during the flow translation more information is available
> as if the recirculation id wasn't found or it was a packet from
> unknown tunnel port.  Printing that information might be useful
> to understand the origin of the problem.
>
> Port translation functions already support extended error strings,
> we just need to pass a variable where to store them.
>
> With the change the output may be:
>
>   |INFO|received packet on unassociated datapath port N
>         (no OpenFlow port for datapath port N)
> or
>   |INFO|received packet on unassociated datapath port N
>         (no OpenFlow tunnel port for this packet)
> or
>   |INFO|received packet on unassociated datapath port N
>         (no recirculation data for recirc_id M)
>
> Unfortunately, there is no good way to trigger this code from
> current unit tests.
>
> Signed-off-by: Ilya Maximets <i.maximets@ovn.org>
> ---
>  ofproto/ofproto-dpif-upcall.c | 27 +++++++++++++++++++--------
>  ofproto/ofproto-dpif-xlate.c  |  6 ++++--
>  ofproto/ofproto-dpif-xlate.h  |  2 +-
>  3 files changed, 24 insertions(+), 11 deletions(-)
>
> diff --git a/ofproto/ofproto-dpif-upcall.c b/ofproto/ofproto-dpif-upcall.c
> index 57f94df54..58671a8aa 100644
> --- a/ofproto/ofproto-dpif-upcall.c
> +++ b/ofproto/ofproto-dpif-upcall.c
> @@ -398,7 +398,8 @@ static int upcall_receive(struct upcall *, const struct dpif_backer *,
>                            const struct dp_packet *packet, enum dpif_upcall_type,
>                            const struct nlattr *userdata, const struct flow *,
>                            const unsigned int mru,
> -                          const ovs_u128 *ufid, const unsigned pmd_id);
> +                          const ovs_u128 *ufid, const unsigned pmd_id,
> +                          char **errorp);
>  static void upcall_uninit(struct upcall *);
>
>  static void udpif_flow_rebalance(struct udpif *udpif);
> @@ -819,6 +820,7 @@ recv_upcalls(struct handler *handler)
>          struct upcall *upcall = &upcalls[n_upcalls];
>          struct flow *flow = &flows[n_upcalls];
>          unsigned int mru = 0;
> +        char *errorp = NULL;
>          uint64_t hash = 0;
>          int error;
>
> @@ -845,7 +847,7 @@ recv_upcalls(struct handler *handler)
>
>          error = upcall_receive(upcall, udpif->backer, &dupcall->packet,
>                                 dupcall->type, dupcall->userdata, flow, mru,
> -                               &dupcall->ufid, PMD_ID_NULL);
> +                               &dupcall->ufid, PMD_ID_NULL, &errorp);
>          if (error) {
>              if (error == ENODEV) {
>                  /* Received packet on datapath port for which we couldn't
> @@ -856,8 +858,11 @@ recv_upcalls(struct handler *handler)
>                                dupcall->key_len, NULL, 0, NULL, 0,
>                                &dupcall->ufid, PMD_ID_NULL, NULL);
>                  VLOG_INFO_RL(&rl, "received packet on unassociated datapath "
> -                             "port %"PRIu32, flow->in_port.odp_port);
> +                             "port %"PRIu32"%s%s%s", flow->in_port.odp_port,
> +                             errorp ? " (" : "", errorp ? errorp : "",
> +                             errorp ? ")" : "");

Wouldn't it just be easier to wrap the whole VLOG_INFO_RL() in an if
statement than have this piecewise string format construction?

I guess that would add a bunch of extra lines, so either is fine.

Acked-by: Mike Pattrick <mkp@redhat.com>

>              }
> +            free(errorp);
>              goto free_dupcall;
>          }
>
> @@ -1143,7 +1148,8 @@ upcall_receive(struct upcall *upcall, const struct dpif_backer *backer,
>                 const struct dp_packet *packet, enum dpif_upcall_type type,
>                 const struct nlattr *userdata, const struct flow *flow,
>                 const unsigned int mru,
> -               const ovs_u128 *ufid, const unsigned pmd_id)
> +               const ovs_u128 *ufid, const unsigned pmd_id,
> +               char **errorp)
>  {
>      int error;
>
> @@ -1152,7 +1158,8 @@ upcall_receive(struct upcall *upcall, const struct dpif_backer *backer,
>          return EAGAIN;
>      } else if (upcall->type == MISS_UPCALL) {
>          error = xlate_lookup(backer, flow, &upcall->ofproto, &upcall->ipfix,
> -                             &upcall->sflow, NULL, &upcall->ofp_in_port);
> +                             &upcall->sflow, NULL, &upcall->ofp_in_port,
> +                             errorp);
>          if (error) {
>              return error;
>          }
> @@ -1160,7 +1167,11 @@ upcall_receive(struct upcall *upcall, const struct dpif_backer *backer,
>          struct ofproto_dpif *ofproto
>              = ofproto_dpif_lookup_by_uuid(&upcall->cookie.ofproto_uuid);
>          if (!ofproto) {
> -            VLOG_INFO_RL(&rl, "upcall could not find ofproto");
> +            if (errorp) {
> +                *errorp = xstrdup("upcall could not find ofproto");
> +            } else {
> +                VLOG_INFO_RL(&rl, "upcall could not find ofproto");
> +            }
>              return ENODEV;
>          }
>          upcall->ofproto = ofproto;
> @@ -1349,7 +1360,7 @@ upcall_cb(const struct dp_packet *packet, const struct flow *flow, ovs_u128 *ufi
>      atomic_read_relaxed(&enable_megaflows, &megaflow);
>
>      error = upcall_receive(&upcall, udpif->backer, packet, type, userdata,
> -                           flow, 0, ufid, pmd_id);
> +                           flow, 0, ufid, pmd_id, NULL);
>      if (error) {
>          return error;
>      }
> @@ -2145,7 +2156,7 @@ xlate_key(struct udpif *udpif, const struct nlattr *key, unsigned int len,
>      }
>
>      error = xlate_lookup(udpif->backer, &ctx->flow, &ofproto, NULL, NULL,
> -                         ctx->netflow, &ofp_in_port);
> +                         ctx->netflow, &ofp_in_port, NULL);
>      if (error) {
>          return error;
>      }
> diff --git a/ofproto/ofproto-dpif-xlate.c b/ofproto/ofproto-dpif-xlate.c
> index 5c3021765..e96697e78 100644
> --- a/ofproto/ofproto-dpif-xlate.c
> +++ b/ofproto/ofproto-dpif-xlate.c
> @@ -1592,17 +1592,19 @@ xlate_lookup_ofproto(const struct dpif_backer *backer, const struct flow *flow,
>   * be taken.
>   *
>   * Returns 0 if successful, ENODEV if the parsed flow has no associated ofproto.
> + * Sets an extended error string to 'errorp'.  Callers are responsible for
> + * freeing that string.
>   */
>  int
>  xlate_lookup(const struct dpif_backer *backer, const struct flow *flow,
>               struct ofproto_dpif **ofprotop, struct dpif_ipfix **ipfix,
>               struct dpif_sflow **sflow, struct netflow **netflow,
> -             ofp_port_t *ofp_in_port)
> +             ofp_port_t *ofp_in_port, char **errorp)
>  {
>      struct ofproto_dpif *ofproto;
>      const struct xport *xport;
>
> -    ofproto = xlate_lookup_ofproto_(backer, flow, ofp_in_port, &xport, NULL);
> +    ofproto = xlate_lookup_ofproto_(backer, flow, ofp_in_port, &xport, errorp);
>
>      if (!ofproto) {
>          return ENODEV;
> diff --git a/ofproto/ofproto-dpif-xlate.h b/ofproto/ofproto-dpif-xlate.h
> index 2ba90e999..c6cb62cdd 100644
> --- a/ofproto/ofproto-dpif-xlate.h
> +++ b/ofproto/ofproto-dpif-xlate.h
> @@ -205,7 +205,7 @@ struct ofproto_dpif * xlate_lookup_ofproto(const struct dpif_backer *,
>  int xlate_lookup(const struct dpif_backer *, const struct flow *,
>                   struct ofproto_dpif **, struct dpif_ipfix **,
>                   struct dpif_sflow **, struct netflow **,
> -                 ofp_port_t *ofp_in_port);
> +                 ofp_port_t *ofp_in_port, char **errorp);
>
>  const char *xlate_strerror(enum xlate_error error);
>
> --
> 2.34.3
>
> _______________________________________________
> dev mailing list
> dev@openvswitch.org
> https://mail.openvswitch.org/mailman/listinfo/ovs-dev
>
Ilya Maximets Oct. 11, 2022, 10:02 p.m. UTC | #2
On 9/29/22 18:40, Mike Pattrick wrote:
> On Thu, Sep 1, 2022 at 11:43 AM Ilya Maximets <i.maximets@ovn.org> wrote:
>>
>> When OVS fails to find an OpenFlow port for a packet received
>> from the upcall it just prints the warning like this:
>>
>>   |INFO|received packet on unassociated datapath port N
>>
>> However, during the flow translation more information is available
>> as if the recirculation id wasn't found or it was a packet from
>> unknown tunnel port.  Printing that information might be useful
>> to understand the origin of the problem.
>>
>> Port translation functions already support extended error strings,
>> we just need to pass a variable where to store them.
>>
>> With the change the output may be:
>>
>>   |INFO|received packet on unassociated datapath port N
>>         (no OpenFlow port for datapath port N)
>> or
>>   |INFO|received packet on unassociated datapath port N
>>         (no OpenFlow tunnel port for this packet)
>> or
>>   |INFO|received packet on unassociated datapath port N
>>         (no recirculation data for recirc_id M)
>>
>> Unfortunately, there is no good way to trigger this code from
>> current unit tests.
>>
>> Signed-off-by: Ilya Maximets <i.maximets@ovn.org>
>> ---
>>  ofproto/ofproto-dpif-upcall.c | 27 +++++++++++++++++++--------
>>  ofproto/ofproto-dpif-xlate.c  |  6 ++++--
>>  ofproto/ofproto-dpif-xlate.h  |  2 +-
>>  3 files changed, 24 insertions(+), 11 deletions(-)
>>
>> diff --git a/ofproto/ofproto-dpif-upcall.c b/ofproto/ofproto-dpif-upcall.c
>> index 57f94df54..58671a8aa 100644
>> --- a/ofproto/ofproto-dpif-upcall.c
>> +++ b/ofproto/ofproto-dpif-upcall.c
>> @@ -398,7 +398,8 @@ static int upcall_receive(struct upcall *, const struct dpif_backer *,
>>                            const struct dp_packet *packet, enum dpif_upcall_type,
>>                            const struct nlattr *userdata, const struct flow *,
>>                            const unsigned int mru,
>> -                          const ovs_u128 *ufid, const unsigned pmd_id);
>> +                          const ovs_u128 *ufid, const unsigned pmd_id,
>> +                          char **errorp);
>>  static void upcall_uninit(struct upcall *);
>>
>>  static void udpif_flow_rebalance(struct udpif *udpif);
>> @@ -819,6 +820,7 @@ recv_upcalls(struct handler *handler)
>>          struct upcall *upcall = &upcalls[n_upcalls];
>>          struct flow *flow = &flows[n_upcalls];
>>          unsigned int mru = 0;
>> +        char *errorp = NULL;
>>          uint64_t hash = 0;
>>          int error;
>>
>> @@ -845,7 +847,7 @@ recv_upcalls(struct handler *handler)
>>
>>          error = upcall_receive(upcall, udpif->backer, &dupcall->packet,
>>                                 dupcall->type, dupcall->userdata, flow, mru,
>> -                               &dupcall->ufid, PMD_ID_NULL);
>> +                               &dupcall->ufid, PMD_ID_NULL, &errorp);
>>          if (error) {
>>              if (error == ENODEV) {
>>                  /* Received packet on datapath port for which we couldn't
>> @@ -856,8 +858,11 @@ recv_upcalls(struct handler *handler)
>>                                dupcall->key_len, NULL, 0, NULL, 0,
>>                                &dupcall->ufid, PMD_ID_NULL, NULL);
>>                  VLOG_INFO_RL(&rl, "received packet on unassociated datapath "
>> -                             "port %"PRIu32, flow->in_port.odp_port);
>> +                             "port %"PRIu32"%s%s%s", flow->in_port.odp_port,
>> +                             errorp ? " (" : "", errorp ? errorp : "",
>> +                             errorp ? ")" : "");
> 
> Wouldn't it just be easier to wrap the whole VLOG_INFO_RL() in an if
> statement than have this piecewise string format construction?
> 
> I guess that would add a bunch of extra lines, so either is fine.

I kept it as-is for now.

> 
> Acked-by: Mike Pattrick <mkp@redhat.com>

Thanks!  Applied.

Best regards, Ilya Maximets.
diff mbox series

Patch

diff --git a/ofproto/ofproto-dpif-upcall.c b/ofproto/ofproto-dpif-upcall.c
index 57f94df54..58671a8aa 100644
--- a/ofproto/ofproto-dpif-upcall.c
+++ b/ofproto/ofproto-dpif-upcall.c
@@ -398,7 +398,8 @@  static int upcall_receive(struct upcall *, const struct dpif_backer *,
                           const struct dp_packet *packet, enum dpif_upcall_type,
                           const struct nlattr *userdata, const struct flow *,
                           const unsigned int mru,
-                          const ovs_u128 *ufid, const unsigned pmd_id);
+                          const ovs_u128 *ufid, const unsigned pmd_id,
+                          char **errorp);
 static void upcall_uninit(struct upcall *);
 
 static void udpif_flow_rebalance(struct udpif *udpif);
@@ -819,6 +820,7 @@  recv_upcalls(struct handler *handler)
         struct upcall *upcall = &upcalls[n_upcalls];
         struct flow *flow = &flows[n_upcalls];
         unsigned int mru = 0;
+        char *errorp = NULL;
         uint64_t hash = 0;
         int error;
 
@@ -845,7 +847,7 @@  recv_upcalls(struct handler *handler)
 
         error = upcall_receive(upcall, udpif->backer, &dupcall->packet,
                                dupcall->type, dupcall->userdata, flow, mru,
-                               &dupcall->ufid, PMD_ID_NULL);
+                               &dupcall->ufid, PMD_ID_NULL, &errorp);
         if (error) {
             if (error == ENODEV) {
                 /* Received packet on datapath port for which we couldn't
@@ -856,8 +858,11 @@  recv_upcalls(struct handler *handler)
                               dupcall->key_len, NULL, 0, NULL, 0,
                               &dupcall->ufid, PMD_ID_NULL, NULL);
                 VLOG_INFO_RL(&rl, "received packet on unassociated datapath "
-                             "port %"PRIu32, flow->in_port.odp_port);
+                             "port %"PRIu32"%s%s%s", flow->in_port.odp_port,
+                             errorp ? " (" : "", errorp ? errorp : "",
+                             errorp ? ")" : "");
             }
+            free(errorp);
             goto free_dupcall;
         }
 
@@ -1143,7 +1148,8 @@  upcall_receive(struct upcall *upcall, const struct dpif_backer *backer,
                const struct dp_packet *packet, enum dpif_upcall_type type,
                const struct nlattr *userdata, const struct flow *flow,
                const unsigned int mru,
-               const ovs_u128 *ufid, const unsigned pmd_id)
+               const ovs_u128 *ufid, const unsigned pmd_id,
+               char **errorp)
 {
     int error;
 
@@ -1152,7 +1158,8 @@  upcall_receive(struct upcall *upcall, const struct dpif_backer *backer,
         return EAGAIN;
     } else if (upcall->type == MISS_UPCALL) {
         error = xlate_lookup(backer, flow, &upcall->ofproto, &upcall->ipfix,
-                             &upcall->sflow, NULL, &upcall->ofp_in_port);
+                             &upcall->sflow, NULL, &upcall->ofp_in_port,
+                             errorp);
         if (error) {
             return error;
         }
@@ -1160,7 +1167,11 @@  upcall_receive(struct upcall *upcall, const struct dpif_backer *backer,
         struct ofproto_dpif *ofproto
             = ofproto_dpif_lookup_by_uuid(&upcall->cookie.ofproto_uuid);
         if (!ofproto) {
-            VLOG_INFO_RL(&rl, "upcall could not find ofproto");
+            if (errorp) {
+                *errorp = xstrdup("upcall could not find ofproto");
+            } else {
+                VLOG_INFO_RL(&rl, "upcall could not find ofproto");
+            }
             return ENODEV;
         }
         upcall->ofproto = ofproto;
@@ -1349,7 +1360,7 @@  upcall_cb(const struct dp_packet *packet, const struct flow *flow, ovs_u128 *ufi
     atomic_read_relaxed(&enable_megaflows, &megaflow);
 
     error = upcall_receive(&upcall, udpif->backer, packet, type, userdata,
-                           flow, 0, ufid, pmd_id);
+                           flow, 0, ufid, pmd_id, NULL);
     if (error) {
         return error;
     }
@@ -2145,7 +2156,7 @@  xlate_key(struct udpif *udpif, const struct nlattr *key, unsigned int len,
     }
 
     error = xlate_lookup(udpif->backer, &ctx->flow, &ofproto, NULL, NULL,
-                         ctx->netflow, &ofp_in_port);
+                         ctx->netflow, &ofp_in_port, NULL);
     if (error) {
         return error;
     }
diff --git a/ofproto/ofproto-dpif-xlate.c b/ofproto/ofproto-dpif-xlate.c
index 5c3021765..e96697e78 100644
--- a/ofproto/ofproto-dpif-xlate.c
+++ b/ofproto/ofproto-dpif-xlate.c
@@ -1592,17 +1592,19 @@  xlate_lookup_ofproto(const struct dpif_backer *backer, const struct flow *flow,
  * be taken.
  *
  * Returns 0 if successful, ENODEV if the parsed flow has no associated ofproto.
+ * Sets an extended error string to 'errorp'.  Callers are responsible for
+ * freeing that string.
  */
 int
 xlate_lookup(const struct dpif_backer *backer, const struct flow *flow,
              struct ofproto_dpif **ofprotop, struct dpif_ipfix **ipfix,
              struct dpif_sflow **sflow, struct netflow **netflow,
-             ofp_port_t *ofp_in_port)
+             ofp_port_t *ofp_in_port, char **errorp)
 {
     struct ofproto_dpif *ofproto;
     const struct xport *xport;
 
-    ofproto = xlate_lookup_ofproto_(backer, flow, ofp_in_port, &xport, NULL);
+    ofproto = xlate_lookup_ofproto_(backer, flow, ofp_in_port, &xport, errorp);
 
     if (!ofproto) {
         return ENODEV;
diff --git a/ofproto/ofproto-dpif-xlate.h b/ofproto/ofproto-dpif-xlate.h
index 2ba90e999..c6cb62cdd 100644
--- a/ofproto/ofproto-dpif-xlate.h
+++ b/ofproto/ofproto-dpif-xlate.h
@@ -205,7 +205,7 @@  struct ofproto_dpif * xlate_lookup_ofproto(const struct dpif_backer *,
 int xlate_lookup(const struct dpif_backer *, const struct flow *,
                  struct ofproto_dpif **, struct dpif_ipfix **,
                  struct dpif_sflow **, struct netflow **,
-                 ofp_port_t *ofp_in_port);
+                 ofp_port_t *ofp_in_port, char **errorp);
 
 const char *xlate_strerror(enum xlate_error error);