From nobody Sun Feb 18 21:11:20 2024 X-Original-To: dev-commits-src-branches@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 4TdJHs0bvKz5BmRS; Sun, 18 Feb 2024 21:11:21 +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 4TdJHr569vz42MQ; Sun, 18 Feb 2024 21:11:20 +0000 (UTC) (envelope-from git@FreeBSD.org) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=freebsd.org; s=dkim; t=1708290680; 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=XMySw36LGPvpcpR2NAU+LxesgO1dqnIZ3Gc3f7YAyNU=; b=M51tHeSwrVS5AzjCP+CKdnolRhhCoTqDWipBXIRyl4MHxn00p8pNWAL3CpU8oUnGkDyGJ7 yQ7rIqb9X9Zw2WBvvXoNHjmDRDR4KYxkNaG3Dbgrz6vHo42WaG7vowEKjIW/NCp2xbK8AW Q6mJDWm9W1vEEN4Qcqqiy074re9pfZrwvoCbvgzcP3hiiT7CcdN27ctrk+FKVdUFr9BJ5c bUyFV6btxGL1K7iF568ISbGfXabvpP/UG5uAWew1z7i309Qa0GycHHhnjrEZDeFPW8Qv+e GEZO8w1TKYFpXYcLTSipZqUGJLzBn+896Mvf7qjacxI7DmHidBumvdL8MxKPkw== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=freebsd.org; s=dkim; t=1708290680; 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=XMySw36LGPvpcpR2NAU+LxesgO1dqnIZ3Gc3f7YAyNU=; b=f30jjUB5IVBbLa4zGwgwEEA8IrhHpt3G7WRNzX+OBZg9AMY903+LpL2Cq14TGKQI4Yh4im 94cpg9E1iJrmXTqoUEyJIyN8nja0ZZezFYza596EzjiSoNz1jRZ+TVz6Cylc+XI95Dxj6j 8ahpJIqVljVwT1eFXkCTiLV3XDvndJ4YlrBAeVZW5Zj3ZBR3BOqJShfscA4fjxxqaDgdXS naSuCU+FqL9v0BhPeMG99ceP1jQIAxeslg23ppe/TUpbZEI0qkX/EKxFljZI/Qp9flLMwi ciJ2O7LtnBMAPBjpgQqyjQaqlLc07DVyrWz51Rbkb6GA3X8Bh6wPjWW6u/0OKA== ARC-Authentication-Results: i=1; mx1.freebsd.org; none ARC-Seal: i=1; s=dkim; d=freebsd.org; t=1708290680; a=rsa-sha256; cv=none; b=w2lwWArXYWa7n/PQHdv0Xgp9B9Ectn1sieJ6UDm4zIdNB2tqZ5HlqLYsOBTfmaPX5UUoKX 8yey1dEbKq5KJikqpbZ9Y/E30ErHv1Ig0hDK/h+XlckuekCnpVpQOnQx1ZiZWJ0K/RbRi2 PTLsppfVlbXkWHtYUaR8I13ZWUNmgBwAB3GJ6QHVaIQcm90KFkCbyruCLev4bWRqlAshEA cJmiJBLwxoE9jKia5H4g78UQL4D3GqmxxcEEShUZ56tLLzIxRlk+IcVjOub6d0i5uUGcmA N8u+GrU7D8UspEfRLq76yeLLSJxA1Luq5a9pEDYECqNRrWBrjx2nJEKMgmhtQw== 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 4TdJHr459zz16S8; Sun, 18 Feb 2024 21:11:20 +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 41ILBKvR015088; Sun, 18 Feb 2024 21:11:20 GMT (envelope-from git@gitrepo.freebsd.org) Received: (from git@localhost) by gitrepo.freebsd.org (8.17.1/8.17.1/Submit) id 41ILBKYv015073; Sun, 18 Feb 2024 21:11:20 GMT (envelope-from git) Date: Sun, 18 Feb 2024 21:11:20 GMT Message-Id: <202402182111.41ILBKYv015073@gitrepo.freebsd.org> To: src-committers@FreeBSD.org, dev-commits-src-all@FreeBSD.org, dev-commits-src-branches@FreeBSD.org From: "Bjoern A. Zeeb" Subject: git: 3df61c29c7aa - stable/14 - net80211: improve logging about state transitions lost List-Id: Commits to the stable branches of the FreeBSD src repository List-Archive: https://lists.freebsd.org/archives/dev-commits-src-branches List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-dev-commits-src-branches@freebsd.org X-BeenThere: dev-commits-src-branches@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/stable/14 X-Git-Reftype: branch X-Git-Commit: 3df61c29c7aa444054a92ed7f4f80d2cd79d1882 Auto-Submitted: auto-generated The branch stable/14 has been updated by bz: URL: https://cgit.FreeBSD.org/src/commit/?id=3df61c29c7aa444054a92ed7f4f80d2cd79d1882 commit 3df61c29c7aa444054a92ed7f4f80d2cd79d1882 Author: Bjoern A. Zeeb AuthorDate: 2023-11-12 23:51:14 +0000 Commit: Bjoern A. Zeeb CommitDate: 2024-02-18 18:31:14 +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 Reviewed by: cc Differential Revision: https://reviews.freebsd.org/D42560 (cherry picked from commit 72bb33a36b62fa30f69f01d3f6ae372be2c95b59) --- 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) {