Re: [PATCH v2] Bug 134: message rate limiting

Hi Anshu, On Tue, 24 Mar 2026 22:23:01 +0530 Anshu Kumari wrote: Please have a look at CONTRIBUTING.md (recently added by Yumei) which should give you an idea of what to write in the commit message. There are also plenty of examples in the mailing list archives, https://archives.passt.top/passt-dev/. Other than the missing commit message and the rather uncommon title format, this is missing a tag: Link: https://bugs.passt.top/show_bug.cgi?id=134 ...and after writing all this, I just realised that Laurent already mentioned all these aspects, see: https://archives.passt.top/passt-dev/26136561-fc90-4f74-9984-aa5fd4e5ca97@re... So, one further comment from me: it's much easier for everybody else (and for you to get code merged) if you address comments before posting a new version. By the way, if you had reviewers on previous versions, it would be nice to Cc: them (I just did), so that they don't miss the fact you posted a new revision they might want to have a look at. And if it's something for me to apply (I currently merge changes), adding me in To: makes it clear to me that this is directed to me (and you get a slightly faster reaction from me this way... usually).

Signed-off-by: Anshu Kumari ---

Here you should explain (not necessarily in detail) what you changed compared to v1. I had just started looking at v1 but I couldn't finish, so I switched to v2, but without any kind of change log I'm not sure if some changes are intended and which pending comments from others you actually meant to take care of. Anyway, restarting from scratch, here's my review:

log.h | 40 ++++++++++++++++++++++++++++++++++++++++ tap.c | 19 ++++++------------- 2 files changed, 46 insertions(+), 13 deletions(-)

diff --git a/log.h b/log.h index 6ceb686..2e9286e 100644 --- a/log.h +++ b/log.h @@ -48,6 +48,46 @@ void logmsg_perror(int pri, const char *format, ...) passt_exit(EXIT_FAILURE); \ } while (0)

+#define LOG_RATELIMIT_BURST 5 /* Max messages per window per call site */ +#define LOG_RATELIMIT_INTERVAL 1 /* Default rate limit window in seconds */

If one starts reading from the top (quite common), it's not clear what the "window" is. If you swap these two lines, it's clearer because you're defining it first by defining LOG_RATELIMIT_INTERVAL ("oh, it's something in seconds"). No need for two spaces between numbers and start of the comments, one is enough.

+ +/** + * logmsg_ratelimit() - Rate-limited log message

This is a bit of a complete sentence, but not quite, and some nouns in a row, but not exactly fitting either. We usually use imperative description for functions, that is, this would be "Log a message with rate limiting". If you prefer to describe the function for what it *is* rather than what it *does* (less common but definitely readable) you could go with "Rate-limited message logging".

+ * @fn: Logging function

To explain why I'm suggesting this: I initially wrote this comment: --- In C you can pass function pointers, so it's not obvious that this doesn't take a function pointer, you should specify that a function *name* is expected, I think. And that function itself isn't really "logging" (even though I understand what you mean, but it's not really immediate). Maybe "Calling function name"? In any case, "Logging function name" would be appropriate as well. --- and realised a couple of minutes later I was wrong. This *is* a function pointer... but it's a macro so it's not really clear from the argument specification. Maybe: "Pointer to logging function", so there's no ambiguity?

+ * @now: current timestamp

For consistency: "Current".

+ */ +#define logmsg_ratelimit(fn, now, ...) \

This is missing a tab (backslashes are not aligned). I would recommend you use an editor showing tabs as 8-character because that's the coding style we use (same as the "networking" Linux kernel coding style). My editor of choice (Geany) also shows (different) graphic signs for tabs and spaces, but I know others use editors without this feature and still get things right so... it must be possible.

+ do { \ + static time_t rl_last_; \ + static unsigned int rl_printed_; \ + static unsigned int rl_suppressed_; \

Very minor, but I guess I'd mention it: see CONTRIBUTING.md for the ordering of variables (so-called reverse Christmas tree) and the rationale behind it.

+ \ + if ((now)->tv_sec - rl_last_ > LOG_RATELIMIT_INTERVAL) { \

Excess tabs -- while it's a bit heavy on eyes, "{\" without spaces is still better than exceeding the usual 80 columns.

+ if (rl_suppressed_) \ + fn("(suppressed %u similar messages)", \

You might have unrelated messages before this one, say, for example: 0.0425: Flow 0 (NEW): FREE -> NEW 0.0425: (suppressed 15 similar messages) 0.0425: Can't process IPv4 fragments (132 dropped) ...now, what does "suppressed 15 similar messages" refer to? It naturally looks like the one before, but it's the one after. That's confusing. Probably the simplest solution to this issue would be to store rl_suppressed_ in a temporary variable, before you zero it, and print this message at the end if (rl_suppressed_), so that it comes after the "similar" message. Or maybe you could just swap the blocks and play a bit with the conditions and save a variable... I haven't tried.

+ rl_suppressed_); \

This comes with the problem that, if we print a bunch of messages in a burst, and then nothing at all, it looks like just five messages were printed. On the other hand, using a timer makes this extremely complicated and probably coupled with substantial overhead. But I guess you could use the trick below (note that I haven't tested it and I didn't really think it through):

+ rl_last_ = (now)->tv_sec; \ + rl_printed_ = 0; \ + rl_suppressed_ = 0; \ + } \ + \ + if (rl_printed_ < LOG_RATELIMIT_BURST) { \ + fn(__VA_ARGS__); \ + rl_printed_++; \ + } else { \

...just when you're about to stop printing messages, that is, when rl_printed_ == LOG_RATELIMIT_BURST, you could print one last message saying and then say, for example, "(suppressing further messages of this type)". So it's clear that there are more, even if we stopped printing them.

+ rl_suppressed_++; \ + } \ + } while (0) + +#define err_ratelimit(now, ...) \

Missing a tab (similar as the occurrence above).

+ logmsg_ratelimit(err, now, __VA_ARGS__) +#define warn_ratelimit(now, ...) \ + logmsg_ratelimit(warn, now, __VA_ARGS__) +#define info_ratelimit(now, ...) \ + logmsg_ratelimit(info, now, __VA_ARGS__) +#define debug_ratelimit(now, ...) \ + logmsg_ratelimit(debug, now, __VA_ARGS__) + extern int log_file; extern int log_trace; extern bool log_conf_parsed; diff --git a/tap.c b/tap.c index 1049e02..656b6e9 100644 --- a/tap.c +++ b/tap.c @@ -686,17 +686,8 @@ static bool tap4_is_fragment(const struct iphdr *iph, const struct timespec *now) { if (ntohs(iph->frag_off) & ~IP_DF) { - /* Ratelimit messages */ - static time_t last_message; - static unsigned num_dropped; - - num_dropped++; - if (now->tv_sec - last_message > FRAGMENT_MSG_RATE) { - warn("Can't process IPv4 fragments (%u dropped)", - num_dropped); - last_message = now->tv_sec; - num_dropped = 0; - } + warn_ratelimit(now, + "Can't process IPv4 fragment");

If you just drop "(%u dropped)", it will be pretty hard to understand the rate at which fragments are being sent: is it one per second or a thousand? That makes a difference while debugging things. I would suggest to keep the 'num_dropped' counter, keep printing the number (without zeroing it, because you don't know when to do it here), and yes, it will wrap eventually (become 0 again), but the wrapping should be very obvious, and it's better than having no indication at all. Now, this is a related change but logically distinct, so it would normally deserve its own patch, which could be in the same series. Look at the archives for examples of series, and at CONTRIBUTING.md for instructions. You could try sending one example series to yourself first, to check. On the other hand I wouldn't find it outrageous to submit this part of change together with the implementation, given it's one example usage (or one implementation you're half-recycling, in some sense). However:

return true; } return false; @@ -1115,8 +1106,10 @@ void tap_add_packet(struct ctx *c, struct iov_tail *data, char bufmac[ETH_ADDRSTRLEN];

memcpy(c->guest_mac, eh->h_source, ETH_ALEN); - debug("New guest MAC address observed: %s", - eth_ntop(c->guest_mac, bufmac, sizeof(bufmac))); + info_ratelimit(now, + "New guest MAC address observed: %s", + eth_ntop(c->guest_mac, bufmac, + sizeof(bufmac)));

...it's different for this part: this is a logically distinct change and it should really be a distinct patch for two reasons: 1. it makes things easier to review 2. it makes it easier to revert things if you introduce an issue, and bisect changes (see git-bisect(1)) if needed Further, this is just one example of what needs to be changed, but you should look for more occurrences of debug messages that can now be promoted to info / warn and include all of them in a separate patch. There should be a few more. I can also have a look if needed, let me know.

proto_update_l2_buf(c->guest_mac); }

-- Stefano