diff mbox

[ovs-dev,2/2] revalidator: Improve logging for transition_ukey().

Message ID CAPWQB7GT7W3za4_6pNmJMGpo0j7-L8QrL5gbObDeHvXsh+qnqQ@mail.gmail.com
State Not Applicable
Headers show

Commit Message

Joe Stringer April 27, 2017, 4:24 p.m. UTC
On 26 April 2017 at 18:35, Jarno Rajahalme <jarno@ovn.org> wrote:
>
>> On Apr 26, 2017, at 6:03 PM, Joe Stringer <joe@ovn.org> wrote:
>>
>> There are a few cases where more introspection into ukey transitions
>> would be relevant for logging or assertion. Track the SOURCE_LOCATOR and
>> thread id when states are transitioned and use these for logging.
>>
>> Suggested-by: Jarno Rajahalme <jarno@ovn.org>
>> Signed-off-by: Joe Stringer <joe@ovn.org>
>> ---
>> ofproto/ofproto-dpif-upcall.c | 17 ++++++++++++++++-
>> 1 file changed, 16 insertions(+), 1 deletion(-)
>>
>> diff --git a/ofproto/ofproto-dpif-upcall.c b/ofproto/ofproto-dpif-upcall.c
>> index ccf15a3c80b3..8aff613161d9 100644
>> --- a/ofproto/ofproto-dpif-upcall.c
>> +++ b/ofproto/ofproto-dpif-upcall.c
>> @@ -281,6 +281,10 @@ struct udpif_key {
>>     uint64_t reval_seq OVS_GUARDED;           /* Tracks udpif->reval_seq. */
>>     enum ukey_state state OVS_GUARDED;        /* Tracks ukey lifetime. */
>>
>> +    /* 'state' debug information. */
>> +    unsigned int state_thread OVS_GUARDED;    /* Thread that transitions. */
>> +    const char *state_where OVS_GUARDED;      /* transition_ukey() locator. */
>> +
>>     /* Datapath flow actions as nlattrs.  Protected by RCU.  Read with
>>      * ukey_get_actions(), and write with ukey_set_actions(). */
>>     OVSRCU_TYPE(struct ofpbuf *) actions;
>> @@ -1484,6 +1488,8 @@ ukey_create__(const struct nlattr *key, size_t key_len,
>>     ukey->dump_seq = dump_seq;
>>     ukey->reval_seq = reval_seq;
>>     ukey->state = UKEY_CREATED;
>> +    ukey->state_thread = ovsthread_id_self();
>> +    ukey->state_where = OVS_SOURCE_LOCATOR;
>>     ukey->created = time_msec();
>>     memset(&ukey->stats, 0, sizeof ukey->stats);
>>     ukey->stats.used = used;
>> @@ -1674,7 +1680,11 @@ static void
>> transition_ukey(struct udpif_key *ukey, enum ukey_state dst)
>>     OVS_REQUIRES(ukey->mutex)
>> {
>> -    ovs_assert(dst >= ukey->state);
>> +    if (dst >= ukey->state) {
>> +        VLOG_ABORT("Invalid ukey transition %d->%d (last transitioned from "
>> +                   "thread %u at %s)", ukey->state, dst, ukey->state_thread,
>> +                   ukey->state_where);
>> +    }
>>     if (ukey->state == dst && dst == UKEY_OPERATIONAL) {
>>         return;
>>     }
>> @@ -1709,6 +1719,8 @@ transition_ukey(struct udpif_key *ukey, enum ukey_state dst)
>>                      ds_cstr(&ds), ukey->state, dst);
>>         ds_destroy(&ds);
>>     }
>> +    ukey->state_thread = ovsthread_id_self();
>> +    ukey->state_where = OVS_SOURCE_LOCATOR;
>
> You’ll want to evaluate OVS_SOURCE_LOCATOR at the caller of the transition_ukey() instead. Top do that you’ll need to add a “const char *where” argument, and then make a macro that uses OVS_SOURCE_LOCATOR as that additional argument, and make the callers use the new macro instead of calling the function directly.
>
> As is it will always report the same line (right here).

Thanks for the reviews. I plan to roll in the following incremental
before applying to master and branch-2.7:

                                      const unsigned pmd_id);
@@ -1677,7 +1680,8 @@ ukey_install__(struct udpif *udpif, struct
udpif_key *new_ukey)
 }

 static void
-transition_ukey(struct udpif_key *ukey, enum ukey_state dst)
+transition_ukey_at(struct udpif_key *ukey, enum ukey_state dst,
+                   const char *where)
     OVS_REQUIRES(ukey->mutex)
 {
     if (dst >= ukey->state) {
@@ -1720,7 +1724,7 @@ transition_ukey(struct udpif_key *ukey, enum
ukey_state dst)
         ds_destroy(&ds);
     }
     ukey->state_thread = ovsthread_id_self();
-    ukey->state_where = OVS_SOURCE_LOCATOR;
+    ukey->state_where = where;
 }

 static bool

Comments

Ben Pfaff April 27, 2017, 4:37 p.m. UTC | #1
On Thu, Apr 27, 2017 at 09:24:04AM -0700, Joe Stringer wrote:
> On 26 April 2017 at 18:35, Jarno Rajahalme <jarno@ovn.org> wrote:
> >
> >> On Apr 26, 2017, at 6:03 PM, Joe Stringer <joe@ovn.org> wrote:
> >>
> >> There are a few cases where more introspection into ukey transitions
> >> would be relevant for logging or assertion. Track the SOURCE_LOCATOR and
> >> thread id when states are transitioned and use these for logging.
> >>
> >> Suggested-by: Jarno Rajahalme <jarno@ovn.org>
> >> Signed-off-by: Joe Stringer <joe@ovn.org>
> >> ---
> >> ofproto/ofproto-dpif-upcall.c | 17 ++++++++++++++++-
> >> 1 file changed, 16 insertions(+), 1 deletion(-)
> >>
> >> diff --git a/ofproto/ofproto-dpif-upcall.c b/ofproto/ofproto-dpif-upcall.c
> >> index ccf15a3c80b3..8aff613161d9 100644
> >> --- a/ofproto/ofproto-dpif-upcall.c
> >> +++ b/ofproto/ofproto-dpif-upcall.c
> >> @@ -281,6 +281,10 @@ struct udpif_key {
> >>     uint64_t reval_seq OVS_GUARDED;           /* Tracks udpif->reval_seq. */
> >>     enum ukey_state state OVS_GUARDED;        /* Tracks ukey lifetime. */
> >>
> >> +    /* 'state' debug information. */
> >> +    unsigned int state_thread OVS_GUARDED;    /* Thread that transitions. */
> >> +    const char *state_where OVS_GUARDED;      /* transition_ukey() locator. */
> >> +
> >>     /* Datapath flow actions as nlattrs.  Protected by RCU.  Read with
> >>      * ukey_get_actions(), and write with ukey_set_actions(). */
> >>     OVSRCU_TYPE(struct ofpbuf *) actions;
> >> @@ -1484,6 +1488,8 @@ ukey_create__(const struct nlattr *key, size_t key_len,
> >>     ukey->dump_seq = dump_seq;
> >>     ukey->reval_seq = reval_seq;
> >>     ukey->state = UKEY_CREATED;
> >> +    ukey->state_thread = ovsthread_id_self();
> >> +    ukey->state_where = OVS_SOURCE_LOCATOR;
> >>     ukey->created = time_msec();
> >>     memset(&ukey->stats, 0, sizeof ukey->stats);
> >>     ukey->stats.used = used;
> >> @@ -1674,7 +1680,11 @@ static void
> >> transition_ukey(struct udpif_key *ukey, enum ukey_state dst)
> >>     OVS_REQUIRES(ukey->mutex)
> >> {
> >> -    ovs_assert(dst >= ukey->state);
> >> +    if (dst >= ukey->state) {
> >> +        VLOG_ABORT("Invalid ukey transition %d->%d (last transitioned from "
> >> +                   "thread %u at %s)", ukey->state, dst, ukey->state_thread,
> >> +                   ukey->state_where);
> >> +    }
> >>     if (ukey->state == dst && dst == UKEY_OPERATIONAL) {
> >>         return;
> >>     }
> >> @@ -1709,6 +1719,8 @@ transition_ukey(struct udpif_key *ukey, enum ukey_state dst)
> >>                      ds_cstr(&ds), ukey->state, dst);
> >>         ds_destroy(&ds);
> >>     }
> >> +    ukey->state_thread = ovsthread_id_self();
> >> +    ukey->state_where = OVS_SOURCE_LOCATOR;
> >
> > You’ll want to evaluate OVS_SOURCE_LOCATOR at the caller of the transition_ukey() instead. Top do that you’ll need to add a “const char *where” argument, and then make a macro that uses OVS_SOURCE_LOCATOR as that additional argument, and make the callers use the new macro instead of calling the function directly.
> >
> > As is it will always report the same line (right here).
> 
> Thanks for the reviews. I plan to roll in the following incremental
> before applying to master and branch-2.7:

Oops.  I feel sad that I missed that!
diff mbox

Patch

diff --git a/ofproto/ofproto-dpif-upcall.c b/ofproto/ofproto-dpif-upcall.c
index 8aff613161d9..25aa8f2a92bc 100644
--- a/ofproto/ofproto-dpif-upcall.c
+++ b/ofproto/ofproto-dpif-upcall.c
@@ -354,8 +354,11 @@  static void ukey_get_actions(struct udpif_key *,
const struct nlattr **actions,
 static bool ukey_install__(struct udpif *, struct udpif_key *ukey)
     OVS_TRY_LOCK(true, ukey->mutex);
 static bool ukey_install(struct udpif *udpif, struct udpif_key *ukey);
-static void transition_ukey(struct udpif_key *ukey, enum ukey_state dst)
+static void transition_ukey_at(struct udpif_key *ukey, enum ukey_state dst,
+                               const char *where)
     OVS_REQUIRES(ukey->mutex);
+#define transition_ukey(UKEY, DST) \
+    transition_ukey_at(UKEY, DST, OVS_SOURCE_LOCATOR)
 static struct udpif_key *ukey_lookup(struct udpif *udpif,
                                      const ovs_u128 *ufid,