From patchwork Thu Apr 27 01:03:12 2017 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Joe Stringer X-Patchwork-Id: 755711 Return-Path: X-Original-To: incoming@patchwork.ozlabs.org Delivered-To: patchwork-incoming@bilbo.ozlabs.org Received: from mail.linuxfoundation.org (mail.linuxfoundation.org [140.211.169.12]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by ozlabs.org (Postfix) with ESMTPS id 3wCzH66qW5z9s84 for ; Thu, 27 Apr 2017 11:04:02 +1000 (AEST) Received: from mail.linux-foundation.org (localhost [127.0.0.1]) by mail.linuxfoundation.org (Postfix) with ESMTP id 2AD46B79; Thu, 27 Apr 2017 01:03:27 +0000 (UTC) X-Original-To: dev@openvswitch.org Delivered-To: ovs-dev@mail.linuxfoundation.org Received: from smtp1.linuxfoundation.org (smtp1.linux-foundation.org [172.17.192.35]) by mail.linuxfoundation.org (Postfix) with ESMTPS id 949BBB79 for ; Thu, 27 Apr 2017 01:03:25 +0000 (UTC) X-Greylist: domain auto-whitelisted by SQLgrey-1.7.6 Received: from relay2-d.mail.gandi.net (relay2-d.mail.gandi.net [217.70.183.194]) by smtp1.linuxfoundation.org (Postfix) with ESMTPS id 161D58C for ; Thu, 27 Apr 2017 01:03:25 +0000 (UTC) Received: from mfilter19-d.gandi.net (mfilter19-d.gandi.net [217.70.178.147]) by relay2-d.mail.gandi.net (Postfix) with ESMTP id D9995C5A63; Thu, 27 Apr 2017 03:03:23 +0200 (CEST) X-Virus-Scanned: Debian amavisd-new at mfilter19-d.gandi.net Received: from relay2-d.mail.gandi.net ([IPv6:::ffff:217.70.183.194]) by mfilter19-d.gandi.net (mfilter19-d.gandi.net [::ffff:10.0.15.180]) (amavisd-new, port 10024) with ESMTP id iG1fyUt5B5sq; Thu, 27 Apr 2017 03:03:22 +0200 (CEST) X-Originating-IP: 208.91.1.34 Received: from carno.eng.vmware.com (unknown [208.91.1.34]) (Authenticated sender: joe@ovn.org) by relay2-d.mail.gandi.net (Postfix) with ESMTPSA id 919BFC5A5A; Thu, 27 Apr 2017 03:03:21 +0200 (CEST) From: Joe Stringer To: dev@openvswitch.org Date: Wed, 26 Apr 2017 18:03:12 -0700 Message-Id: <20170427010312.18249-2-joe@ovn.org> X-Mailer: git-send-email 2.11.1 In-Reply-To: <20170427010312.18249-1-joe@ovn.org> References: <20170427010312.18249-1-joe@ovn.org> X-Spam-Status: No, score=-2.1 required=5.0 tests=BAYES_00, RCVD_IN_DNSWL_LOW, RCVD_IN_SORBS_SPAM autolearn=ham version=3.3.1 X-Spam-Checker-Version: SpamAssassin 3.3.1 (2010-03-16) on smtp1.linux-foundation.org Cc: aatteka@ovn.org Subject: [ovs-dev] [PATCH 2/2] revalidator: Improve logging for transition_ukey(). X-BeenThere: ovs-dev@openvswitch.org X-Mailman-Version: 2.1.12 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , MIME-Version: 1.0 Sender: ovs-dev-bounces@openvswitch.org Errors-To: ovs-dev-bounces@openvswitch.org 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 Signed-off-by: Joe Stringer Acked-by: Ben Pfaff --- 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; } static bool @@ -2327,6 +2339,9 @@ revalidate(struct revalidator *revalidator) /* The flow is now confirmed to be in the datapath. */ transition_ukey(ukey, UKEY_OPERATIONAL); } else { + VLOG_INFO("Unexpected ukey transition from state %d " + "(last transitioned from thread %u at %s)", + ukey->state, ukey->state_thread, ukey->state_where); ovs_mutex_unlock(&ukey->mutex); continue; }