From nobody Fri Dec 22 00:19:47 2023 X-Original-To: dev-commits-src-main@mlmmj.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mlmmj.nyi.freebsd.org (Postfix) with ESMTP id 4Sx7GX1t0bz54SnP; Fri, 22 Dec 2023 00:19:48 +0000 (UTC) (envelope-from git@FreeBSD.org) Received: from mxrelay.nyi.freebsd.org (mxrelay.nyi.freebsd.org [IPv6:2610:1c1:1:606c::19:3]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256 client-signature RSA-PSS (4096 bits) client-digest SHA256) (Client CN "mxrelay.nyi.freebsd.org", Issuer "R3" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 4Sx7GX182pz4fdy; Fri, 22 Dec 2023 00:19:48 +0000 (UTC) (envelope-from git@FreeBSD.org) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=freebsd.org; s=dkim; t=1703204388; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding; bh=yv2YBaPWqKKmd1LvLRZcUjVuxH9AUbFKoExf2sGLzPg=; b=bckLcQN1ypv6XVPZWBFcNKhQZlLDfmTezIG3ffc3K1B463gMQ+RFFArvG0bkundEm/cMPq WaLqzUGrN2BxaAKdTQLkFL7AXuybqeTJL4BAtmd6xTR5tiutujoBjPzh/hOsdwhlzuCEt4 AeboAqmdvjuyIF4l7LtKpXxuMvJuqWQKs+kPQyb70mrusyXCiPQbdIhYBK9HgepIjxsskP OJ644ByAOVHFDC0y2rhmPMjFLpXC190I+5CIXvZNmqTZkv53EqUS65OO0xfvy6v7pGW8/x J3W8Jxsdus8my5wT0G52ZT6p88PWEQURHJqk+sw4sM2fbED28H8UFzusLWbsvA== ARC-Seal: i=1; s=dkim; d=freebsd.org; t=1703204388; a=rsa-sha256; cv=none; b=Fd8Xhf+UlrBzcAxbLTQ8nRkHaF4KIyKxLKxV7wTHRxXlo6TEHaKsAx6gkyoeqOIUGtl2kb vacARMb3qBb/AGptP4Kj9Di/joFLo41FDkhAh9QPYtBykpg0JJw91zT1d1cSN/KV1uowcw cbmcgNUO53czhBeduq42RHIo3+0+tYhRXTaiuOaVMi7/CyW7LUR2XSQVPrmrQWebYsEVsO 9jPbfV5lJ/f/Zm4hVGPYlNK1l3KN2Ts6YPfBwzyo6raG0Rd/a80xQGnwAFgQvLQEogiYdz KawMwY0MbbLD7XyPkmnm7rOVY38Izx09O5ThGRe9+0N4qyF7hz9gRbSGl/wTAQ== ARC-Authentication-Results: i=1; mx1.freebsd.org; none ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=freebsd.org; s=dkim; t=1703204388; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding; bh=yv2YBaPWqKKmd1LvLRZcUjVuxH9AUbFKoExf2sGLzPg=; b=wtBMycsuuUvIWXy4T5JKPP1S1PVWbd71IQDndJfO0veUsj6m+zdYBrIpcd01RAzvfpQY0P pQ9RsVRVQC1w+iYUgPB078jFJfUd0ubDWr2Z3/Qou9XCXZe/deGUbtykCXDj2R8JbWTH/a 6omFcfvJa9ILbImvcfEKynYhax1S8kpzYpySJpQkJcjfJMG2nobR1gnYcLQMOFyqj83W8C CyP9EGWA6HY0LNgCUHXCX8ALzuIsFNDHU7x4APjbqZHG/t4biCESbgaXt0Ie/ZMLuaeki3 JVu6GznPdjsNT3I/fF5DGDEL2Kg1WfmQXQisZ0v4FMf7Av6bREJr8fKKcSx4FA== Received: from gitrepo.freebsd.org (gitrepo.freebsd.org [IPv6:2610:1c1:1:6068::e6a:5]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256) (Client did not present a certificate) by mxrelay.nyi.freebsd.org (Postfix) with ESMTPS id 4Sx7GX0BnkzttZ; Fri, 22 Dec 2023 00:19:48 +0000 (UTC) (envelope-from git@FreeBSD.org) Received: from gitrepo.freebsd.org ([127.0.1.44]) by gitrepo.freebsd.org (8.17.1/8.17.1) with ESMTP id 3BM0Jlkf037169; Fri, 22 Dec 2023 00:19:47 GMT (envelope-from git@gitrepo.freebsd.org) Received: (from git@localhost) by gitrepo.freebsd.org (8.17.1/8.17.1/Submit) id 3BM0JlIB037166; Fri, 22 Dec 2023 00:19:47 GMT (envelope-from git) Date: Fri, 22 Dec 2023 00:19:47 GMT Message-Id: <202312220019.3BM0JlIB037166@gitrepo.freebsd.org> To: src-committers@FreeBSD.org, dev-commits-src-all@FreeBSD.org, dev-commits-src-main@FreeBSD.org From: "Bjoern A. Zeeb" Subject: git: 72bb33a36b62 - main - net80211: improve logging about state transitions lost List-Id: Commit messages for the main branch of the src repository List-Archive: https://lists.freebsd.org/archives/dev-commits-src-main List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-dev-commits-src-main@freebsd.org X-BeenThere: dev-commits-src-main@freebsd.org MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 8bit X-Git-Committer: bz X-Git-Repository: src X-Git-Refname: refs/heads/main X-Git-Reftype: branch X-Git-Commit: 72bb33a36b62fa30f69f01d3f6ae372be2c95b59 Auto-Submitted: auto-generated The branch main has been updated by bz: URL: https://cgit.FreeBSD.org/src/commit/?id=72bb33a36b62fa30f69f01d3f6ae372be2c95b59 commit 72bb33a36b62fa30f69f01d3f6ae372be2c95b59 Author: Bjoern A. Zeeb AuthorDate: 2023-11-12 23:51:14 +0000 Commit: Bjoern A. Zeeb CommitDate: 2023-12-22 00:19:05 +0000 net80211: improve logging about state transitions lost It is possible that we call ieee80211_new_state_locked() again before a previous task finished to completion (not run yet or unlocked in between) since 5efea30f039c4 (and follow-up). In either case we would overwrite the new state and argument in the vap. While most drivers somehow deal with that (or not), LinuxKPI 802.11 compat code has KASSERTs to keep net80211, LinuxKPI and driver/firmware state in sync and they may trigger due to a missing transition or more likely a changed ni/lsta. Enhance the wlandebug +state logging for these cases so they are easier to debug. While here remove the unconditional logging to the message buffer; it has been here for a good decade but not helped to actually identify and sort the problem. Sponsored by: The FreeBSD Foundation MFC after: 3 days Reviewed by: cc Differential Revision: https://reviews.freebsd.org/D42560 --- sys/net80211/ieee80211_proto.c | 32 ++++++++++++++++++++------------ 1 file changed, 20 insertions(+), 12 deletions(-) diff --git a/sys/net80211/ieee80211_proto.c b/sys/net80211/ieee80211_proto.c index cf170463372b..a3a2e6a5d027 100644 --- a/sys/net80211/ieee80211_proto.c +++ b/sys/net80211/ieee80211_proto.c @@ -2506,6 +2506,13 @@ ieee80211_newstate_cb(void *xvap, int npending) nstate = vap->iv_nstate; arg = vap->iv_nstate_arg; + IEEE80211_DPRINTF(vap, IEEE80211_MSG_STATE, + "%s:%d: running state update %s -> %s (%d)\n", + __func__, __LINE__, + ieee80211_state_name[vap->iv_state], + ieee80211_state_name[vap->iv_nstate], + npending); + if (vap->iv_flags_ext & IEEE80211_FEXT_REINIT) { /* * We have been requested to drop back to the INIT before @@ -2673,29 +2680,30 @@ ieee80211_new_state_locked(struct ieee80211vap *vap, * until this is completed. */ IEEE80211_DPRINTF(vap, IEEE80211_MSG_STATE, - "%s: %s -> %s (%s) transition discarded\n", - __func__, + "%s:%d: %s -> %s (%s) transition discarded\n", + __func__, __LINE__, ieee80211_state_name[vap->iv_state], ieee80211_state_name[nstate], ieee80211_state_name[vap->iv_nstate]); return -1; } else if (vap->iv_state != vap->iv_nstate) { -#if 0 /* Warn if the previous state hasn't completed. */ IEEE80211_DPRINTF(vap, IEEE80211_MSG_STATE, - "%s: pending %s -> %s transition lost\n", __func__, + "%s:%d: pending %s -> %s (now to %s) transition lost\n", + __func__, __LINE__, ieee80211_state_name[vap->iv_state], - ieee80211_state_name[vap->iv_nstate]); -#else - /* XXX temporarily enable to identify issues */ - if_printf(vap->iv_ifp, - "%s: pending %s -> %s transition lost\n", - __func__, ieee80211_state_name[vap->iv_state], - ieee80211_state_name[vap->iv_nstate]); -#endif + ieee80211_state_name[vap->iv_nstate], + ieee80211_state_name[nstate]); } } + IEEE80211_DPRINTF(vap, IEEE80211_MSG_STATE, + "%s:%d: starting state update %s -> %s (%s)\n", + __func__, __LINE__, + ieee80211_state_name[vap->iv_state], + ieee80211_state_name[vap->iv_nstate], + ieee80211_state_name[nstate]); + nrunning = nscanning = 0; /* XXX can track this state instead of calculating */ TAILQ_FOREACH(vp, &ic->ic_vaps, iv_next) {