From nobody Mon Feb 19 16:10:18 2024 X-Original-To: dev-commits-src-all@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 4TdnZ323ZMz5C4q8; Mon, 19 Feb 2024 16:10:19 +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 4TdnZ30GQ3z4Ntd; Mon, 19 Feb 2024 16:10:19 +0000 (UTC) (envelope-from git@FreeBSD.org) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=freebsd.org; s=dkim; t=1708359019; 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=vqQlyR6tekwdTgn1i65MWepJUt1+zT9EQVOm4BHf1Pc=; b=gfiq9KbjZv2acS2tVJQjerDbLXnJ6sBJ3n10qavZK1hXGDFegwxkRbBujSO2f8Yc27kRWf 5gUxNBubr1VsIOT0Hh1g9652PFeV7sdPLBI5PYI3pCL00ZafMPo0Cvt9uUzq9xjvHtweVd lEq5k4MKGF680KaZotfLQiUdLn14oZsIDUFSD/7ibuh24A8SprvTaAml22m4D1zGf3xEDH dZGc84enkJN01f9cuCLbmL22vkdNnXash9oCFnzgdJo3nvgyDcJi8qN1Mr86jC8CpECPkh dYcSPNnr7hSR3NtKyIfhBkDvy4u0CoHwRe+IV6PjpeiSS0nPc2hOJ9lpEtcL3g== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=freebsd.org; s=dkim; t=1708359019; 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=vqQlyR6tekwdTgn1i65MWepJUt1+zT9EQVOm4BHf1Pc=; b=w79yQb3Q2gqH3I7zhwllhHdedJNq4W6BzjSMHczNXZGC1i+in4lF7fhBgGTyTBeneiJ13E R4c08nKP/OAwKrI+6DMzbwxcLe+ixAMkqLMAKmNhIcKkCxK5RobS1mcOb6PuYQH24wRFW+ Hg/kUNBEHibuZK+/D1G33ITFtVoicyPSU7dgd2st9Luc34QxlRgBPa8/ZQ2bSEHb2Dh95l yT8O2Xj7Qeq07y3CwFPPGoW1jegg8tD10Oq3V4/nSY+uuWdKOx+b22qCk9wfFzKTyVFvG+ F7UFFHqJfqdqBIIQ71E4wh4ctNG+4j68beyYGTnaINRu47cWHKEZfO1Gd2kUfg== ARC-Authentication-Results: i=1; mx1.freebsd.org; none ARC-Seal: i=1; s=dkim; d=freebsd.org; t=1708359019; a=rsa-sha256; cv=none; b=hoM7PzeA7ePuoBvyPW668NyaP6eD3rr2Q6vDIiQPJXmoini6EQDOY5sladobmyBDhC3JEr 5HoUKrTjsM2grPs2VVxxePcv/aoC76SQZWnEa/7wG++H/q/N798pOWfZskQOptj3D/9tlH nOTxr2EbAZNR/CRcbj6mrWZuyr6YFwqnMqGTvwVM3ycX8/fbDzGpYfhL8XLCQePJ2hV4y+ 49smQMmmSeUjpI/ynBLntjU6Nod360IPVAn80BA8MW5jgWRxOQRkokGPN8SN+jUhCPRymM r+t+B79Z2a4nxHpfyIhHXnPxbf2qwo6nyDimrW5d2MjmO9pDsBmKcBsQkmynQQ== 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 4TdnZ26TzSzhPf; Mon, 19 Feb 2024 16:10:18 +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 41JGAIoJ035737; Mon, 19 Feb 2024 16:10:18 GMT (envelope-from git@gitrepo.freebsd.org) Received: (from git@localhost) by gitrepo.freebsd.org (8.17.1/8.17.1/Submit) id 41JGAIOA035734; Mon, 19 Feb 2024 16:10:18 GMT (envelope-from git) Date: Mon, 19 Feb 2024 16:10:18 GMT Message-Id: <202402191610.41JGAIOA035734@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: f93d06ac87f4 - releng/13.3 - net80211: improve logging about state transitions lost List-Id: Commit messages for all branches of the src repository List-Archive: https://lists.freebsd.org/archives/dev-commits-src-all List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-dev-commits-src-all@freebsd.org X-BeenThere: dev-commits-src-all@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/releng/13.3 X-Git-Reftype: branch X-Git-Commit: f93d06ac87f4d5f496fe5669dc56b912e11c136e Auto-Submitted: auto-generated The branch releng/13.3 has been updated by bz: URL: https://cgit.FreeBSD.org/src/commit/?id=f93d06ac87f4d5f496fe5669dc56b912e11c136e commit f93d06ac87f4d5f496fe5669dc56b912e11c136e Author: Bjoern A. Zeeb AuthorDate: 2023-11-12 23:51:14 +0000 Commit: Bjoern A. Zeeb CommitDate: 2024-02-19 16:06:51 +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. Approved by: re (cperciva) Sponsored by: The FreeBSD Foundation Reviewed by: cc Differential Revision: https://reviews.freebsd.org/D42560 (cherry picked from commit 72bb33a36b62fa30f69f01d3f6ae372be2c95b59) (cherry picked from commit a2764047702db519aca9e1b3cf6b475e5a723c65) --- 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 f6d144169c48..cf467c08462c 100644 --- a/sys/net80211/ieee80211_proto.c +++ b/sys/net80211/ieee80211_proto.c @@ -2510,6 +2510,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 @@ -2677,29 +2684,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) {