Re: [PATCH] ath10k: change len of trace_ath10k_log_dbg_dump for large buffer size

[Brian Norris <briannorris@chromium.org>]

+ Steven Rostedt

Hi Wen,

(Trimming down the description a bit:)

On Mon, Feb 8, 2021 at 6:59 PM Wen Gong <wgong@codeaurora.org> wrote:
>
> Kernel panic every time in kernel when running below case:
> steps:
> 1. connect to an AP with good signal strength
> 2. echo 0x7f > /sys/kernel/debug/ieee80211/phy0/ath10k/pktlog_filter
> 3. echo 0xffff 0 > /sys/kernel/debug/ieee80211/phy0/ath10k/fw_dbglog
> 4. echo 0 > /sys/module/ath10k_core/parameters/debug_mask
> 5. sudo trace-cmd record  -e ath10k
> 6. run "iperf -c 192.168.1.1 -u -b 100m -i 1 -t 30"
> 7. kernel panic immeditely
>
> It always crash at trace_event_raw_event_ath10k_xxx, below is 2 sample:
...
> The value of prog in filter_match_preds of kernel/trace/trace_events_filter.c
> is overwrite to the content of the UDP packets's content like this
> 0x0039383736353433, it is a invalid address, so crash.
...
> ath10k_htc_send_bundle_skbs allocate skb with size 49792(1556*32), it
> is bigger than PAGE_SIZE which is normally 4096, then ath10k_sdio_write
> call ath10k_dbg_dump to trace the large size skb and corrupt the trace
> data of tracing and lead crash. When disable the TX bundle of SDIO, it
> does not crash, but TX bundle is for improve throughput, so it is enabled
> by default. It is useless to call ath10k_dbg_dump to trace the large
> bundled skb, so this patch trace the top part of large bundled skb.
...
> trace_event_raw_event_ath10k_log_dbg_dump is generated by compiler, it
> call trace_event_buffer_reserve got get a struct pointer *entry, its
> type is trace_event_raw_ath10k_log_dbg_dump which is also generated by
> compiler, trace_event_buffer_reserve of kernel/trace/trace_events.c
> call trace_event_buffer_lock_reserve to get ring_buffer_event.
>
> In function trace_event_buffer_lock_reserve of kernel/trace/trace.c,
> the ring_buffer_time_stamp_abs is false and trace_file->flags is 0x40b
> which is set bit of EVENT_FILE_FL_FILTERED by debugging, so it use the
> temp buffer this_cpu_read(trace_buffered_event), and the buffer size
> is 1 page size which allocatee in trace_buffered_event_enable by
> alloc_pages_node, and then ath10k pass the buffer size > 1 page trigger
> overflow and crash.
>
> Based on upper test, try and debugging, pass large buff size to function
> trace_ath10k_log_dbg_dump cause crash, and it has ath10k_dbg in
> ath10k_sdio_write to print the length of skb/buffer, it is not necessary
> to trace all content of the large skb.

Is this the same issue noted in this thread?

[for-next][PATCH 2/2] tracing: Use temp buffer when filtering events
https://lore.kernel.org/lkml/f16b14066317f6a926b6636df6974966@codeaurora.org/

It seems like we should still try to get that fixed somehow, even if
the below change is fine on its own (it probably doesn't make sense to
such a large amount of data via tracepoints). It would be unfortunate
for next poor soul to hit the same issues, just because they wanted to
dump a few KB.

Brian

>  drivers/net/wireless/ath/ath10k/debug.c | 2 +-
>  drivers/net/wireless/ath/ath10k/debug.h | 2 ++
>  2 files changed, 3 insertions(+), 1 deletion(-)
>
> diff --git a/drivers/net/wireless/ath/ath10k/debug.c b/drivers/net/wireless/ath/ath10k/debug.c
> index e8250a665433..5433dbdde0e5 100644
> --- a/drivers/net/wireless/ath/ath10k/debug.c
> +++ b/drivers/net/wireless/ath/ath10k/debug.c
> @@ -2718,7 +2718,7 @@ void ath10k_dbg_dump(struct ath10k *ar,
>
>         /* tracing code doesn't like null strings :/ */
>         trace_ath10k_log_dbg_dump(ar, msg ? msg : "", prefix ? prefix : "",
> -                                 buf, len);
> +                                 buf, min_t(size_t, len, ATH10K_LOG_DUMP_MAX));
>  }
>  EXPORT_SYMBOL(ath10k_dbg_dump);
>
> diff --git a/drivers/net/wireless/ath/ath10k/debug.h b/drivers/net/wireless/ath/ath10k/debug.h
> index 997c1c80aba7..cec9ba92f28f 100644
> --- a/drivers/net/wireless/ath/ath10k/debug.h
> +++ b/drivers/net/wireless/ath/ath10k/debug.h
> @@ -11,6 +11,8 @@
>  #include <linux/types.h>
>  #include "trace.h"
>
> +#define ATH10K_LOG_DUMP_MAX 1024
> +
>  enum ath10k_debug_mask {
>         ATH10K_DBG_PCI          = 0x00000001,
>         ATH10K_DBG_WMI          = 0x00000002,
> --
> 2.23.0
>
>
> _______________________________________________
> ath10k mailing list
> ath10k@lists.infradead.org
> http://lists.infradead.org/mailman/listinfo/ath10k

_______________________________________________
ath10k mailing list
ath10k@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/ath10k