trace_printk is meant as a debugging tool, and should not be compiled into production code without specific debug Kconfig options enabled or source code changes.
Patches 1 to 3 remove/disable trace_printk that should not be enabled by default.
Patch 4 adds a config option that can be used to detect such trace_printk at compile time (instead of printing a nasty warning at runtime).
Nicolas Boichat (4): usb: cdns3: gadget: Replace trace_printk by dev_dbg media: atomisp: Replace trace_printk by pr_info media: camss: vfe: Use trace_printk for debugging only kernel/trace: Add TRACING_ALLOW_PRINTK config option
drivers/gpu/drm/i915/Kconfig.debug | 4 ++-- .../media/platform/qcom/camss/camss-vfe-4-1.c | 2 ++ .../media/platform/qcom/camss/camss-vfe-4-7.c | 2 ++ drivers/staging/media/atomisp/pci/hmm/hmm.c | 10 +++++----- drivers/usb/cdns3/gadget.c | 2 +- fs/f2fs/Kconfig | 1 + include/linux/kernel.h | 17 ++++++++++++++++- kernel/trace/Kconfig | 10 ++++++++++ samples/Kconfig | 2 ++ 9 files changed, 41 insertions(+), 9 deletions(-)
trace_printk should not be used in production code, replace it call with dev_dbg.
Signed-off-by: Nicolas Boichat drinkcat@chromium.org
---
Unclear why a trace_printk was used in the first place, it's possible that some rate-limiting is necessary here.
drivers/usb/cdns3/gadget.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/drivers/usb/cdns3/gadget.c b/drivers/usb/cdns3/gadget.c index 5e24c2e57c0d8c8..c303ab7c62d1651 100644 --- a/drivers/usb/cdns3/gadget.c +++ b/drivers/usb/cdns3/gadget.c @@ -421,7 +421,7 @@ static int cdns3_start_all_request(struct cdns3_device *priv_dev, if ((priv_req->flags & REQUEST_INTERNAL) || (priv_ep->flags & EP_TDLCHK_EN) || priv_ep->use_streams) { - trace_printk("Blocking external request\n"); + dev_dbg(priv_dev->dev, "Blocking external request\n"); return ret; } }
On 20-06-27 15:03:04, Nicolas Boichat wrote:
trace_printk should not be used in production code, replace it call with dev_dbg.
Signed-off-by: Nicolas Boichat drinkcat@chromium.org
Unclear why a trace_printk was used in the first place, it's possible that some rate-limiting is necessary here.
drivers/usb/cdns3/gadget.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/drivers/usb/cdns3/gadget.c b/drivers/usb/cdns3/gadget.c index 5e24c2e57c0d8c8..c303ab7c62d1651 100644 --- a/drivers/usb/cdns3/gadget.c +++ b/drivers/usb/cdns3/gadget.c @@ -421,7 +421,7 @@ static int cdns3_start_all_request(struct cdns3_device *priv_dev, if ((priv_req->flags & REQUEST_INTERNAL) || (priv_ep->flags & EP_TDLCHK_EN) || priv_ep->use_streams) {
trace_printk("Blocking external request\n");
} }dev_dbg(priv_dev->dev, "Blocking external request\n"); return ret;
--
Reviewed-by: Peter Chen peter.chen@nxp.com
Nicolas Boichat drinkcat@chromium.org writes:
trace_printk should not be used in production code, replace it call with dev_dbg.
Signed-off-by: Nicolas Boichat drinkcat@chromium.org
Unclear why a trace_printk was used in the first place, it's possible that some rate-limiting is necessary here.
drivers/usb/cdns3/gadget.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/drivers/usb/cdns3/gadget.c b/drivers/usb/cdns3/gadget.c index 5e24c2e57c0d8c8..c303ab7c62d1651 100644 --- a/drivers/usb/cdns3/gadget.c +++ b/drivers/usb/cdns3/gadget.c @@ -421,7 +421,7 @@ static int cdns3_start_all_request(struct cdns3_device *priv_dev, if ((priv_req->flags & REQUEST_INTERNAL) || (priv_ep->flags & EP_TDLCHK_EN) || priv_ep->use_streams) {
trace_printk("Blocking external request\n");
dev_dbg(priv_dev->dev, "Blocking external request\n");
Instead, I would suggest adding a proper trace event here; one that includes "priv_ep->flags" in the output.
On Thu, Jul 23, 2020 at 9:17 PM Felipe Balbi balbi@kernel.org wrote:
Nicolas Boichat drinkcat@chromium.org writes:
trace_printk should not be used in production code, replace it call with dev_dbg.
Signed-off-by: Nicolas Boichat drinkcat@chromium.org
Unclear why a trace_printk was used in the first place, it's possible that some rate-limiting is necessary here.
drivers/usb/cdns3/gadget.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/drivers/usb/cdns3/gadget.c b/drivers/usb/cdns3/gadget.c index 5e24c2e57c0d8c8..c303ab7c62d1651 100644 --- a/drivers/usb/cdns3/gadget.c +++ b/drivers/usb/cdns3/gadget.c @@ -421,7 +421,7 @@ static int cdns3_start_all_request(struct cdns3_device *priv_dev, if ((priv_req->flags & REQUEST_INTERNAL) || (priv_ep->flags & EP_TDLCHK_EN) || priv_ep->use_streams) {
trace_printk("Blocking external request\n");
dev_dbg(priv_dev->dev, "Blocking external request\n");
Instead, I would suggest adding a proper trace event here; one that includes "priv_ep->flags" in the output.
The patch was already merged by Greg (https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/commit/d...), but feel free to do that as a follow-up CL.
Looks like Peter -- the main author, is ok with dev_dbg (also, apologies for missing the R-b tag when I sent a v2 -- which is the one that was merged by Greg).
Thanks,
-- balbi
Nicolas Boichat drinkcat@chromium.org writes:
On Thu, Jul 23, 2020 at 9:17 PM Felipe Balbi balbi@kernel.org wrote:
Nicolas Boichat drinkcat@chromium.org writes:
trace_printk should not be used in production code, replace it call with dev_dbg.
Signed-off-by: Nicolas Boichat drinkcat@chromium.org
Unclear why a trace_printk was used in the first place, it's possible that some rate-limiting is necessary here.
drivers/usb/cdns3/gadget.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/drivers/usb/cdns3/gadget.c b/drivers/usb/cdns3/gadget.c index 5e24c2e57c0d8c8..c303ab7c62d1651 100644 --- a/drivers/usb/cdns3/gadget.c +++ b/drivers/usb/cdns3/gadget.c @@ -421,7 +421,7 @@ static int cdns3_start_all_request(struct cdns3_device *priv_dev, if ((priv_req->flags & REQUEST_INTERNAL) || (priv_ep->flags & EP_TDLCHK_EN) || priv_ep->use_streams) {
trace_printk("Blocking external request\n");
dev_dbg(priv_dev->dev, "Blocking external request\n");
Instead, I would suggest adding a proper trace event here; one that includes "priv_ep->flags" in the output.
The patch was already merged by Greg (https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/commit/d...), but feel free to do that as a follow-up CL.
Looks like Peter -- the main author, is ok with dev_dbg (also, apologies for missing the R-b tag when I sent a v2 -- which is the one that was merged by Greg).
That's okay, we can get a proper trace event for v5.10. Maybe Pawel or Roger would like to take the effort?
trace_printk should not be used in production code, replace it call with pr_info.
Signed-off-by: Nicolas Boichat drinkcat@chromium.org
--- drivers/staging/media/atomisp/pci/hmm/hmm.c | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-)
diff --git a/drivers/staging/media/atomisp/pci/hmm/hmm.c b/drivers/staging/media/atomisp/pci/hmm/hmm.c index 42fef17798622f1..2bd39b4939f16d2 100644 --- a/drivers/staging/media/atomisp/pci/hmm/hmm.c +++ b/drivers/staging/media/atomisp/pci/hmm/hmm.c @@ -735,11 +735,11 @@ ia_css_ptr hmm_host_vaddr_to_hrt_vaddr(const void *ptr)
void hmm_show_mem_stat(const char *func, const int line) { - trace_printk("tol_cnt=%d usr_size=%d res_size=%d res_cnt=%d sys_size=%d dyc_thr=%d dyc_size=%d.\n", - hmm_mem_stat.tol_cnt, - hmm_mem_stat.usr_size, hmm_mem_stat.res_size, - hmm_mem_stat.res_cnt, hmm_mem_stat.sys_size, - hmm_mem_stat.dyc_thr, hmm_mem_stat.dyc_size); + pr_info("tol_cnt=%d usr_size=%d res_size=%d res_cnt=%d sys_size=%d dyc_thr=%d dyc_size=%d.\n", + hmm_mem_stat.tol_cnt, + hmm_mem_stat.usr_size, hmm_mem_stat.res_size, + hmm_mem_stat.res_cnt, hmm_mem_stat.sys_size, + hmm_mem_stat.dyc_thr, hmm_mem_stat.dyc_size); }
void hmm_init_mem_stat(int res_pgnr, int dyc_en, int dyc_pgnr)
trace_printk should not be used in production code. Since tracing interrupts is presumably latency sensitive, pr_dbg is not appropriate, so guard the call with a preprocessor symbol that can be defined for debugging purpose.
Signed-off-by: Nicolas Boichat drinkcat@chromium.org
--- drivers/media/platform/qcom/camss/camss-vfe-4-1.c | 2 ++ drivers/media/platform/qcom/camss/camss-vfe-4-7.c | 2 ++ 2 files changed, 4 insertions(+)
diff --git a/drivers/media/platform/qcom/camss/camss-vfe-4-1.c b/drivers/media/platform/qcom/camss/camss-vfe-4-1.c index 174a36be6f5d866..0c57171fae4f9e9 100644 --- a/drivers/media/platform/qcom/camss/camss-vfe-4-1.c +++ b/drivers/media/platform/qcom/camss/camss-vfe-4-1.c @@ -936,8 +936,10 @@ static irqreturn_t vfe_isr(int irq, void *dev)
vfe->ops->isr_read(vfe, &value0, &value1);
+#ifdef CAMSS_VFE_TRACE_IRQ trace_printk("VFE: status0 = 0x%08x, status1 = 0x%08x\n", value0, value1); +#endif
if (value0 & VFE_0_IRQ_STATUS_0_RESET_ACK) vfe->isr_ops.reset_ack(vfe); diff --git a/drivers/media/platform/qcom/camss/camss-vfe-4-7.c b/drivers/media/platform/qcom/camss/camss-vfe-4-7.c index 0dca8bf9281e774..307675925e5c779 100644 --- a/drivers/media/platform/qcom/camss/camss-vfe-4-7.c +++ b/drivers/media/platform/qcom/camss/camss-vfe-4-7.c @@ -1058,8 +1058,10 @@ static irqreturn_t vfe_isr(int irq, void *dev)
vfe->ops->isr_read(vfe, &value0, &value1);
+#ifdef CAMSS_VFE_TRACE_IRQ trace_printk("VFE: status0 = 0x%08x, status1 = 0x%08x\n", value0, value1); +#endif
if (value0 & VFE_0_IRQ_STATUS_0_RESET_ACK) vfe->isr_ops.reset_ack(vfe);
trace_printk is meant as a debugging tool, and should not be compiled into production code without specific debug Kconfig options enabled, or source code changes, as indicated by the warning that shows up on boot if any trace_printk is called: ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** ** ** ** trace_printk() being used. Allocating extra memory. ** ** ** ** This means that this is a DEBUG kernel and it is ** ** unsafe for production use. **
If this option is set to n, the kernel will generate a build-time error if trace_printk is used.
Note that the code to handle trace_printk is still present, so this does not prevent people from compiling out-of-tree kernel modules with the option set to =y, or BPF programs.
Signed-off-by: Nicolas Boichat drinkcat@chromium.org
---
Changes since v1: - Use static_assert instead of __static_assert (Jason Gunthorpe) - Fix issues that can be detected by this patch (running some randconfig in a loop, kernel test robot, or manual inspection), by: - Making some debug config options that use trace_printk depend on the new config option. - Adding 3 patches before this one.
There is a question from Alexei whether the warning is warranted, and it's possibly too strongly worded, but the fact is, we do not want trace_printk to be sprinkled in kernel code by default, unless a very specific Kconfig command is enabled (or preprocessor macro).
There's at least 3 reasons that I can come up with: 1. trace_printk introduces some overhead. 2. If the kernel keeps adding always-enabled trace_printk, it will be much harder for developers to make use of trace_printk for debugging. 3. People may assume that trace_printk is for debugging only, and may accidentally output sensitive data (theoritical at this stage).
drivers/gpu/drm/i915/Kconfig.debug | 4 ++-- fs/f2fs/Kconfig | 1 + include/linux/kernel.h | 17 ++++++++++++++++- kernel/trace/Kconfig | 10 ++++++++++ samples/Kconfig | 2 ++ 5 files changed, 31 insertions(+), 3 deletions(-)
diff --git a/drivers/gpu/drm/i915/Kconfig.debug b/drivers/gpu/drm/i915/Kconfig.debug index 1cb28c20807c59d..fa30f9bdc82311f 100644 --- a/drivers/gpu/drm/i915/Kconfig.debug +++ b/drivers/gpu/drm/i915/Kconfig.debug @@ -84,7 +84,7 @@ config DRM_I915_ERRLOG_GEM config DRM_I915_TRACE_GEM bool "Insert extra ftrace output from the GEM internals" depends on DRM_I915_DEBUG_GEM - select TRACING + depends on TRACING_ALLOW_PRINTK default n help Enable additional and verbose debugging output that will spam @@ -98,7 +98,7 @@ config DRM_I915_TRACE_GEM config DRM_I915_TRACE_GTT bool "Insert extra ftrace output from the GTT internals" depends on DRM_I915_DEBUG_GEM - select TRACING + depends on TRACING_ALLOW_PRINTK default n help Enable additional and verbose debugging output that will spam diff --git a/fs/f2fs/Kconfig b/fs/f2fs/Kconfig index d13c5c6a978769b..d161d96cc1b7418 100644 --- a/fs/f2fs/Kconfig +++ b/fs/f2fs/Kconfig @@ -80,6 +80,7 @@ config F2FS_IO_TRACE bool "F2FS IO tracer" depends on F2FS_FS depends on FUNCTION_TRACER + depends on TRACING_ALLOW_PRINTK help F2FS IO trace is based on a function trace, which gathers process information and block IO patterns in the filesystem level. diff --git a/include/linux/kernel.h b/include/linux/kernel.h index 196607aaf653082..8abce95b0c95a0e 100644 --- a/include/linux/kernel.h +++ b/include/linux/kernel.h @@ -721,10 +721,15 @@ do { \ #define trace_printk(fmt, ...) \ do { \ char _______STR[] = __stringify((__VA_ARGS__)); \ + \ + static_assert( \ + IS_ENABLED(CONFIG_TRACING_ALLOW_PRINTK),\ + "trace_printk called, please enable CONFIG_TRACING_ALLOW_PRINTK."); \ + \ if (sizeof(_______STR) > 3) \ do_trace_printk(fmt, ##__VA_ARGS__); \ else \ - trace_puts(fmt); \ + do_trace_puts(fmt); \ } while (0)
#define do_trace_printk(fmt, args...) \ @@ -773,6 +778,13 @@ int __trace_printk(unsigned long ip, const char *fmt, ...); */
#define trace_puts(str) ({ \ + static_assert( \ + IS_ENABLED(CONFIG_TRACING_ALLOW_PRINTK), \ + "trace_puts called, please enable CONFIG_TRACING_ALLOW_PRINTK."); \ + do_trace_puts(str); \ +}) + +#define do_trace_puts(str) ({ \ static const char *trace_printk_fmt __used \ __attribute__((section("__trace_printk_fmt"))) = \ __builtin_constant_p(str) ? str : NULL; \ @@ -794,6 +806,9 @@ extern void trace_dump_stack(int skip); */ #define ftrace_vprintk(fmt, vargs) \ do { \ + static_assert( \ + IS_ENABLED(CONFIG_TRACING_ALLOW_PRINTK), \ + "ftrace_vprintk called, please enable CONFIG_TRACING_ALLOW_PRINTK."); \ if (__builtin_constant_p(fmt)) { \ static const char *trace_printk_fmt __used \ __attribute__((section("__trace_printk_fmt"))) = \ diff --git a/kernel/trace/Kconfig b/kernel/trace/Kconfig index a4020c0b4508c99..971b6035b197823 100644 --- a/kernel/trace/Kconfig +++ b/kernel/trace/Kconfig @@ -111,6 +111,15 @@ config GENERIC_TRACER bool select TRACING
+config TRACING_ALLOW_PRINTK + bool "Allow trace_printk" + default y if DEBUG_KERNEL + depends on TRACING + help + trace_printk is only meant as a debugging tool. If this option is + set to n, the kernel will generate a build-time error if trace_printk + is used. + # # Minimum requirements an architecture has to meet for us to # be able to offer generic tracing facilities: @@ -686,6 +695,7 @@ config TRACEPOINT_BENCHMARK config RING_BUFFER_BENCHMARK tristate "Ring buffer benchmark stress tester" depends on RING_BUFFER + depends on TRACING_ALLOW_PRINTK help This option creates a test to stress the ring buffer and benchmark it. It creates its own ring buffer such that it will not interfere with diff --git a/samples/Kconfig b/samples/Kconfig index 0ed6e4d71d87b16..6b1ade57f00dd5d 100644 --- a/samples/Kconfig +++ b/samples/Kconfig @@ -19,6 +19,7 @@ config SAMPLE_TRACE_EVENTS config SAMPLE_TRACE_PRINTK tristate "Build trace_printk module - tests various trace_printk formats" depends on EVENT_TRACING && m + depends on TRACING_ALLOW_PRINTK help This builds a module that calls trace_printk() and can be used to test various trace_printk() calls from a module. @@ -26,6 +27,7 @@ config SAMPLE_TRACE_PRINTK config SAMPLE_FTRACE_DIRECT tristate "Build register_ftrace_direct() example" depends on DYNAMIC_FTRACE_WITH_DIRECT_CALLS && m + depends on TRACING_ALLOW_PRINTK depends on X86_64 # has x86_64 inlined asm help This builds an ftrace direct function example
dri-devel@lists.freedesktop.org