| Message ID | 20240806-e810-live-migration-rd32-poll-timeout-v1-4-b5ada29ce703@intel.com |
|---|---|
| State | Accepted |
| Delegated to: | Anthony Nguyen |
| Headers | show |
| Series | ice: refactor and cleanup control queue logic | expand |
> -----Original Message----- > From: Intel-wired-lan <intel-wired-lan-bounces@osuosl.org> On Behalf Of Jacob Keller > Sent: Wednesday, August 7, 2024 2:16 AM > To: Nguyen, Anthony L <anthony.l.nguyen@intel.com>; Intel Wired LAN <intel-wired-lan@lists.osuosl.org>; "netdev netdev"@vger.kernel.org > Cc: Temerkhanov, Sergey <sergey.temerkhanov@intel.com>; Kitszel, Przemyslaw <przemyslaw.kitszel@intel.com>; Kolacinski, Karol <karol.kolacinski@intel.com>; Wierzbicki, Jacek <jacek.wierzbicki@intel.com> > Subject: [Intel-wired-lan] [PATCH iwl-next 4/7] ice: stop intermixing AQ commands/responses debug dumps > > From: Przemek Kitszel <przemyslaw.kitszel@intel.com> > > The ice_debug_cq() function is called to generate a debug log of control queue messages both sent and received. It currently does this over a potential total of 6 different printk invocations. > > The main logic prints over 4 calls to ice_debug(): > > 1. The metadata including opcode, flags, datalength and return value. > 2. The cookie in the descriptor. > 3. The parameter values. > 4. The address for the databuffer. > > In addition, if the descriptor has a data buffer, it can be logged with two additional prints: > > 5. A message indicating the start of the data buffer. > 6. The actual data buffer, printed using print_hex_dump_debug. > > This can lead to trouble in the event that two different PFs are logging messages. The messages become intermixed and it may not be possible to determine which part of the output belongs to which control queue message. > > To fix this, it needs to be possible to unambiguously determine which messages belong together. This is trivial for the messages that comprise the main printing. Combine them together into a single invocation of ice_debug(). > > The message containing a hex-dump of the data buffer is a bit more complicated. This is printed separately as part of print_hex_dump_debug. > This function takes a prefix, which is currently always set to KBUILD_MODNAME. Extend this prefix to include the buffer address for the databuffer, which is printed as part of the main print, and which is guaranteed to be unique for each buffer. > > Refactor the ice_debug_array(), introducing an ice_debug_array_w_prefix(). > Build the prefix by combining KBUILD_MODNAME with the databuffer address using snprintf(). > > These changes make it possible to unambiguously determine what data belongs to what control queue message. > > Reported-by: Jacek Wierzbicki <jacek.wierzbicki@intel.com> > Signed-off-by: Przemek Kitszel <przemyslaw.kitszel@intel.com> > Signed-off-by: Jacob Keller <jacob.e.keller@intel.com> > --- > drivers/net/ethernet/intel/ice/ice_osdep.h | 24 ++++++++++++++---------- > drivers/net/ethernet/intel/ice/ice_controlq.c | 21 +++++++++++---------- > 2 files changed, 25 insertions(+), 20 deletions(-) > Tested-by: Pucha Himasekhar Reddy <himasekharx.reddy.pucha@intel.com> (A Contingent worker at Intel)
diff --git a/drivers/net/ethernet/intel/ice/ice_osdep.h b/drivers/net/ethernet/intel/ice/ice_osdep.h index 9882e6f3b26d..b9f383494b3f 100644 --- a/drivers/net/ethernet/intel/ice/ice_osdep.h +++ b/drivers/net/ethernet/intel/ice/ice_osdep.h @@ -43,11 +43,10 @@ struct device *ice_hw_to_dev(struct ice_hw *hw); #define ice_debug(hw, type, fmt, args...) \ dev_dbg(ice_hw_to_dev(hw), fmt, ##args) -#define ice_debug_array(hw, type, rowsize, groupsize, buf, len) \ - print_hex_dump_debug(KBUILD_MODNAME " ", \ - DUMP_PREFIX_OFFSET, rowsize, \ - groupsize, buf, len, false) -#else +#define _ice_debug_array(hw, type, prefix, rowsize, groupsize, buf, len) \ + print_hex_dump_debug(prefix, DUMP_PREFIX_OFFSET, \ + rowsize, groupsize, buf, len, false) +#else /* CONFIG_DYNAMIC_DEBUG */ #define ice_debug(hw, type, fmt, args...) \ do { \ if ((type) & (hw)->debug_mask) \ @@ -55,16 +54,15 @@ do { \ } while (0) #ifdef DEBUG -#define ice_debug_array(hw, type, rowsize, groupsize, buf, len) \ +#define _ice_debug_array(hw, type, prefix, rowsize, groupsize, buf, len) \ do { \ if ((type) & (hw)->debug_mask) \ - print_hex_dump_debug(KBUILD_MODNAME, \ - DUMP_PREFIX_OFFSET, \ + print_hex_dump_debug(prefix, DUMP_PREFIX_OFFSET,\ rowsize, groupsize, buf, \ len, false); \ } while (0) -#else -#define ice_debug_array(hw, type, rowsize, groupsize, buf, len) \ +#else /* DEBUG */ +#define _ice_debug_array(hw, type, prefix, rowsize, groupsize, buf, len) \ do { \ struct ice_hw *hw_l = hw; \ if ((type) & (hw_l)->debug_mask) { \ @@ -82,4 +80,10 @@ do { \ #endif /* DEBUG */ #endif /* CONFIG_DYNAMIC_DEBUG */ +#define ice_debug_array(hw, type, rowsize, groupsize, buf, len) \ + _ice_debug_array(hw, type, KBUILD_MODNAME, rowsize, groupsize, buf, len) + +#define ice_debug_array_w_prefix(hw, type, prefix, buf, len) \ + _ice_debug_array(hw, type, prefix, 16, 1, buf, len) + #endif /* _ICE_OSDEP_H_ */ diff --git a/drivers/net/ethernet/intel/ice/ice_controlq.c b/drivers/net/ethernet/intel/ice/ice_controlq.c index ddf07b773313..020600de9533 100644 --- a/drivers/net/ethernet/intel/ice/ice_controlq.c +++ b/drivers/net/ethernet/intel/ice/ice_controlq.c @@ -936,17 +936,14 @@ static void ice_debug_cq(struct ice_hw *hw, struct ice_ctl_q_info *cq, datalen = le16_to_cpu(cq_desc->datalen); flags = le16_to_cpu(cq_desc->flags); - ice_debug(hw, ICE_DBG_AQ_DESC, "%s %s: opcode 0x%04X, flags 0x%04X, datalen 0x%04X, retval 0x%04X\n", + ice_debug(hw, ICE_DBG_AQ_DESC, "%s %s: opcode 0x%04X, flags 0x%04X, datalen 0x%04X, retval 0x%04X\n\tcookie (h,l) 0x%08X 0x%08X\n\tparam (0,1) 0x%08X 0x%08X\n\taddr (h,l) 0x%08X 0x%08X\n", ice_ctl_q_str(cq->qtype), response ? "Response" : "Command", le16_to_cpu(cq_desc->opcode), flags, datalen, - le16_to_cpu(cq_desc->retval)); - ice_debug(hw, ICE_DBG_AQ_DESC, "\tcookie (h,l) 0x%08X 0x%08X\n", + le16_to_cpu(cq_desc->retval), le32_to_cpu(cq_desc->cookie_high), - le32_to_cpu(cq_desc->cookie_low)); - ice_debug(hw, ICE_DBG_AQ_DESC, "\tparam (0,1) 0x%08X 0x%08X\n", + le32_to_cpu(cq_desc->cookie_low), le32_to_cpu(cq_desc->params.generic.param0), - le32_to_cpu(cq_desc->params.generic.param1)); - ice_debug(hw, ICE_DBG_AQ_DESC, "\taddr (h,l) 0x%08X 0x%08X\n", + le32_to_cpu(cq_desc->params.generic.param1), le32_to_cpu(cq_desc->params.generic.addr_high), le32_to_cpu(cq_desc->params.generic.addr_low)); /* Dump buffer iff 1) one exists and 2) is either a response indicated @@ -954,10 +951,14 @@ static void ice_debug_cq(struct ice_hw *hw, struct ice_ctl_q_info *cq, */ if (buf && cq_desc->datalen && (flags & (ICE_AQ_FLAG_DD | ICE_AQ_FLAG_CMP | ICE_AQ_FLAG_RD))) { - ice_debug(hw, ICE_DBG_AQ_DESC_BUF, "Buffer:\n"); + char prefix[] = KBUILD_MODNAME " 0x12341234 0x12341234 "; - ice_debug_array(hw, ICE_DBG_AQ_DESC_BUF, 16, 1, buf, - min_t(u16, buf_len, datalen)); + sprintf(prefix, KBUILD_MODNAME " 0x%08X 0x%08X ", + le32_to_cpu(cq_desc->params.generic.addr_high), + le32_to_cpu(cq_desc->params.generic.addr_low)); + ice_debug_array_w_prefix(hw, ICE_DBG_AQ_DESC_BUF, prefix, + buf, + min_t(u16, buf_len, datalen)); } }