Its tautological that having pr_debug()s with optional print-once and
rate-limiting features could be useful. Build it, they will come.
The advantages:
- dynamically configured with flags
- can use them on existing callsites
- printonce is easy, (almost) just new flags
no additional resources
- ratelimiting is pooled, expecting rare use
provisioned only for enabled & ratelimited callsites
- RFC ratelimit grouping
mostly to reduce resources
reduces to choice of hash key: module, function, file, line
Whats done here:
Expand ddebug.flags to 11 bits, and define new flags to support
print-once and ratelimited semantics:
echo file init/main.c +o > control # init/main runs just once anyway
echo module foo +r > control # turn on ratelimiting
echo module foo +g > control # turn on group flag
is_onced_or_ratelimited() tests these conditions, it is called from
__dynamic_pr_debug() and others (which are all behind the '+p'
enablement test).
NB: test_dynamic_debug.ko ratelimiting test triggers reports on
is_onced_or_ratelimited() as the limited source.
PRINT-ONCE: can be done with just +2 bits in flags;
.o _DPRINTK_FLAGS_ONCE enables state test and set
.P _DPRINTK_FLAGS_PRINTED state bit
Just adding the flags lets the existing code operate on them.
We will need new code to enforce constraints on flag combos;
'+ro' is nonsense, but this can wait, or can take a new meaning.
RATE-LIMITING:
.r _DPRINTK_FLAGS_RATELIMITED - track & limit prdbgs callrate
We wait until a prdebug is called, and if RATELIMITED is set, THEN
lookup a RateLimitState (RL) for it. If found, bump its state and
return true/false, otherwise create & initialize one and return false.
RFC: GROUP-FLAG:
.g _DPRINTK_FLAGS_GROUPED
Currently, the hash-key is just the prdebug descriptor, so is unique
per prdebug. With the 'g' flag, we could use a different key, for
example desc->site.function, to get a shared ratelimit for whole
functions.
This gets subtly different behavior at the ratelimit transition, but
it is predictable for a given function (except perhaps recursive, but
thats not done anyway).
Note also that any function can have a single group of prdebugs, plus
any number of prdbgs without 'g', either with or without 'r'. So
grouping should be flexible enough to use advantageously.
Signed-off-by: Jim Cromie <jim.cromie@xxxxxxxxx>
---
v6: new to patchset
---
include/linux/dynamic_debug.h | 19 ++++--
lib/dynamic_debug.c | 125 +++++++++++++++++++++++++++++++++-
2 files changed, 137 insertions(+), 7 deletions(-)
diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
index 8807367c7903..e9871557cff1 100644
--- a/include/linux/dynamic_debug.h
+++ b/include/linux/dynamic_debug.h
@@ -28,26 +28,33 @@ struct _ddebug {
* writes commands to <debugfs>/dynamic_debug/control
*/
#define _DPRINTK_FLAGS_NONE 0
-#define _DPRINTK_FLAGS_PRINT (1<<0) /* printk() a message */
+#define _DPRINTK_FLAGS_PRINT (1<<4) /* printk() a message */
#define _DPRINTK_FLAGS_PRINT_TRACE (1<<5) /* call (*tracer) */
#define _DPRINTK_ENABLED (_DPRINTK_FLAGS_PRINT | _DPRINTK_FLAGS_PRINT_TRACE)
-#define _DPRINTK_FLAGS_INCL_MODNAME (1<<1)
-#define _DPRINTK_FLAGS_INCL_FUNCNAME (1<<2)
-#define _DPRINTK_FLAGS_INCL_LINENO (1<<3)
-#define _DPRINTK_FLAGS_INCL_TID (1<<4)
+#define _DPRINTK_FLAGS_INCL_MODNAME (1<<0)
+#define _DPRINTK_FLAGS_INCL_FUNCNAME (1<<1)
+#define _DPRINTK_FLAGS_INCL_LINENO (1<<2)
+#define _DPRINTK_FLAGS_INCL_TID (1<<3)
#define _DPRINTK_FLAGS_INCL_ANY \
(_DPRINTK_FLAGS_INCL_MODNAME | _DPRINTK_FLAGS_INCL_FUNCNAME |\
_DPRINTK_FLAGS_INCL_LINENO | _DPRINTK_FLAGS_INCL_TID)
+#define _DPRINTK_FLAGS_ONCE (1<<6) /* print once flag */
+#define _DPRINTK_FLAGS_PRINTED (1<<7) /* print once state */
+#define _DPRINTK_FLAGS_RATELIMITED (1<<8)
+#define _DPRINTK_FLAGS_GROUPED (1<<9) /* manipulate as a group */
+#define _DPRINTK_FLAGS_DELETE_SITE (1<<10) /* drop site info to save ram */
+
#if defined DEBUG
#define _DPRINTK_FLAGS_DEFAULT _DPRINTK_FLAGS_PRINT
#else
#define _DPRINTK_FLAGS_DEFAULT 0
#endif
- unsigned int flags:8;
+ unsigned int flags:11;
+
#ifdef CONFIG_JUMP_LABEL
union {
struct static_key_true dd_key_true;
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 60bf2c01db1a..16e4db04082b 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -83,13 +83,19 @@ static inline const char *trim_prefix(const char *path)
return path + skip;
}
-static struct { unsigned flag:8; char opt_char; } opt_array[] = {
+static struct { unsigned flag:12; char opt_char; } opt_array[] = {
{ _DPRINTK_FLAGS_PRINT, 'p' },
{ _DPRINTK_FLAGS_PRINT_TRACE, 'T' },
{ _DPRINTK_FLAGS_INCL_MODNAME, 'm' },
{ _DPRINTK_FLAGS_INCL_FUNCNAME, 'f' },
{ _DPRINTK_FLAGS_INCL_LINENO, 'l' },
{ _DPRINTK_FLAGS_INCL_TID, 't' },
+
+ { _DPRINTK_FLAGS_ONCE, 'o' },
+ { _DPRINTK_FLAGS_PRINTED, 'P' },
+ { _DPRINTK_FLAGS_RATELIMITED, 'r' },
+ { _DPRINTK_FLAGS_GROUPED, 'g' },
+ { _DPRINTK_FLAGS_DELETE_SITE, 'D' },
{ _DPRINTK_FLAGS_NONE, '_' },
};
@@ -119,6 +125,8 @@ do { \
#define vpr_info(fmt, ...) vnpr_info(1, fmt, ##__VA_ARGS__)
#define v2pr_info(fmt, ...) vnpr_info(2, fmt, ##__VA_ARGS__)
+#define v3pr_info(fmt, ...) vnpr_info(3, fmt, ##__VA_ARGS__)
+#define v4pr_info(fmt, ...) vnpr_info(4, fmt, ##__VA_ARGS__)
static void vpr_info_dq(const struct ddebug_query *query, const char *msg)
{
@@ -725,6 +733,49 @@ static inline char *dynamic_emit_prefix(struct _ddebug *desc, char *buf)
return buf;
}
+struct ddebug_ratelimit {
+ struct hlist_node hnode;
+ struct ratelimit_state rs;
+ u64 key;
+};
+
+/* test print-once or ratelimited conditions */
+#define is_rated(desc) unlikely(desc->flags & _DPRINTK_FLAGS_RATELIMITED)
+#define is_once(desc) unlikely(desc->flags & _DPRINTK_FLAGS_ONCE)
+#define is_onced(desc) \
+ unlikely((desc->flags & _DPRINTK_FLAGS_ONCE) \
+ && (desc->flags & _DPRINTK_FLAGS_PRINTED))
+
+static struct ddebug_ratelimit *ddebug_rl_fetch(struct _ddebug *desc);
+
+static inline bool is_onced_or_limited(struct _ddebug *desc)
+{
+ if (unlikely(desc->flags & _DPRINTK_FLAGS_ONCE &&
+ desc->flags & _DPRINTK_FLAGS_RATELIMITED))
+ pr_info(" ONCE & RATELIMITED together is nonsense\n");
+
+ if (is_once(desc)) {
+ if (is_onced(desc)) {
+ v4pr_info("already printed once\n");
+ return true;
+ }
+ desc->flags |= _DPRINTK_FLAGS_PRINTED;
+ return false;
+
+ } else if (is_rated(desc)) {
+ /* test rate-limits */
+ bool state = __ratelimit(&ddebug_rl_fetch(desc)->rs);
+
+ v4pr_info("RLstate{%s}=%d on %s.%s.%d\n",
+ (desc->flags & _DPRINTK_FLAGS_GROUPED
+ ? "grouped" : "solo"), state,
+ desc->modname, desc->function, desc->lineno);
+
+ return state;
+ }
+ return false;
+}
+
void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...)
{
va_list args;
@@ -734,6 +785,9 @@ void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...)
BUG_ON(!descriptor);
BUG_ON(!fmt);
+ if (is_onced_or_limited(descriptor))
+ return;
+
va_start(args, fmt);
vaf.fmt = fmt;
@@ -766,6 +820,9 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor,
BUG_ON(!descriptor);
BUG_ON(!fmt);
+ if (is_onced_or_limited(descriptor))
+ return;
+
va_start(args, fmt);
vaf.fmt = fmt;
@@ -797,6 +854,9 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor,
BUG_ON(!descriptor);
BUG_ON(!fmt);
+ if (is_onced_or_limited(descriptor))
+ return;
+
va_start(args, fmt);
vaf.fmt = fmt;
@@ -833,6 +893,9 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
struct va_format vaf;
va_list args;
+ if (is_onced_or_limited(descriptor))
+ return;
+
va_start(args, fmt);
vaf.fmt = fmt;
@@ -1307,3 +1370,63 @@ int dynamic_debug_unregister_tracer(const char *query, const char *modname,
return ddebug_exec_queries(query, modname, tracer);
}
EXPORT_SYMBOL(dynamic_debug_unregister_tracer);
+
+/*
+ * Rate-Limited debug is expected to rarely be needed, so it is
+ * provisioned on-demand when an enabled and rate-limit-flagged
+ * pr_debug is called, by ddebug_rl_fetch(). For now, key is just
+ * descriptor, so is unique per site.
+
+ * Plan: for 'gr' flagged callsites, choose a key that is same across
+ * all prdebugs in a function, to apply a single rate-limit to the
+ * whole function. This should give nearly identical behavior at much
+ * lower memory cost.
+ */
+static DEFINE_HASHTABLE(ddebug_rl_map, 6);
+
+static struct ddebug_ratelimit *ddebug_rl_find(u64 key)
+{
+ struct ddebug_ratelimit *limiter;
+
+ hash_for_each_possible(ddebug_rl_map, limiter, hnode, key) {
+ if (limiter->key == key)
+ return limiter;
+ }
+ return NULL;
+}
+
+/* Must be called with ddebug_rl_lock locked. */
+static struct ddebug_ratelimit *ddebug_rl_add(u64 key)
+{
+ struct ddebug_ratelimit *limiter;
+
+ limiter = ddebug_rl_find(key);
+ if (limiter)
+ return limiter;
+ limiter = kmalloc(sizeof(*limiter), GFP_ATOMIC);
+ if (!limiter)
+ return ERR_PTR(-ENOMEM);
+
+ limiter->key = key;
+ ratelimit_default_init(&limiter->rs);
+ hash_add(ddebug_rl_map, &limiter->hnode, key);
+
+ v3pr_info("added %llx\n", key);
+ return limiter;
+}
+
+/*
+ * called when enabled callsite has _DPRINTK_FLAGS_RATELIMITED flag
+ * set (echo +pr >control), it hashes on &table-header+index
+ */
+static struct ddebug_ratelimit *ddebug_rl_fetch(struct _ddebug *desc)
+{
+ u64 key = (u64)desc;
+ struct ddebug_ratelimit *ddebug_rl = ddebug_rl_find(key);
+
+ if (ddebug_rl) {
+ v4pr_info("found %llx\n", key);
+ return ddebug_rl;
+ }
+ return ddebug_rl_add(key);
+}
--
2.31.1
