io_wait: run the fd-map consistency check only with EXTRA_DEBUG

[Lt-Flash]

Summary

check_io_data() in io_wait.h is a consistency pass over the reactor's fd map — every one of the max_fd_no entries — and it runs on every io_watch_add() and io_watch_del(). The macro is defined unconditionally, so the plain build pays it too.

That makes each async registration or removal O(reactor size), i.e. O(open_files_limit). Measured on a 16-core host with a 21k-entry reactor (open_files_limit 65536, reactor shrunk to 20971 by the pkg budget): ~0.6 ms per call. A module doing a few thousand async operations a second — here cross-node cache pulls through the async framework, but any async DB or REST traffic takes the same path — spent about two cores in it: io_watch_add/io_watch_del were the largest user-space symbols of a perf profile at 13.6% of all CPU, and the receive buffers of the SIP sockets overflowed (129 UdpRcvbufErrors over a run) because the workers were busy walking the map.

Change

The check is compiled only with EXTRA_DEBUG; the plain build keeps check_error cleared and does nothing. No behaviour change otherwise.

Effect

Same workload, same host, before → after: async-heavy worker CPU down by the two cores, UDP receive drops 129 → 0, request p95 in the early part of the run 0.97 → 0.91 ms; the check still runs in EXTRA_DEBUG builds.

Built with gcc and clang under -Werror.

[bogdan-iancu]

Hi @Lt-Flash - indeed, the check may be costly, I agree. But it was added while trying to debug some reports related to the TCP reactor. So I see some need for it, without going thru the pain of re-compiling (as we had in the past with the memory allocators) - so maybe we should do this as core param option or so ? something you can on/off without re-compiling.

[Lt-Flash]

Hi Bogdan, thank you for taking the time to look at this, and for the context — I hadn't appreciated that the check was born out of real TCP reactor reports, which changes the picture. You're right that something you can switch on without recompiling is worth far more than a compile-time flag, and the allocator history makes the point well. I'm happy to rework the PR along those lines.

If I may float a suggestion for the shape, I'd lean towards mirroring what memdump/memlog already do rather than adding a bare on/off switch: a core parameter reactor_check holding a log level (default L_DBG + 12, i.e. 16 — above the normal debug level, so existing setups see no change), with the fd-map walk in check_io_data() gated on is_printable(reactor_check). The nice property is that it becomes switchable live, per process, through the MI log_level command — no rebuild, no restart, no new MI to maintain — while keeping exactly what the check is good at: firing on the very io_watch_add/io_watch_del that breaks the map, so it points at the culprit rather than just at the aftermath. When off it costs a single integer compare, and like memdump it's an explicit opt-in — a plain log_level = 4 won't pull it in by surprise.

If you'd rather keep it simpler, a straightforward boolean reactor_fd_check = true|false (off by default, on in EXTRA_DEBUG builds) works just as well — same gate, applied at startup, without the runtime toggle. I'm genuinely fine with either; you know the reactor's debugging needs far better than I do.

For reference, the numbers that prompted the PR in the first place: about 0.6 ms per call on a 21k-entry reactor, and roughly 13.6% of host CPU with a module doing ~1,500 async operations per second, with UDP drops under load that go away once the walk is off.

Whichever you prefer, I'll update the PR (code plus the Script-CoreParameters.md entry) right away. Thanks again for the review!

---

Option 1 — reactor_check, a log level (my preference)

Definition: a core parameter holding a log level. The fd-map consistency walk in check_io_data() runs on a given io_watch_add()/io_watch_del() only if the process's current log_level is at or above reactor_check. Default L_DBG + 12 (16), so it is off unless explicitly enabled; enable it in the config, or at runtime on one process with the MI log_level command. Five files, roughly 35 lines.

io_wait.h — the current PR's #ifdef EXTRA_DEBUG pair becomes one runtime-gated macro:

-/* ... A debugging aid, so it is one only with EXTRA_DEBUG; the plain
- * build sets check_error to 0 and moves on. */
-#ifdef EXTRA_DEBUG
+/* ... A debugging aid for reactor / fd-map reports: it runs only when the
+ * core parameter reactor_check (a log level, default L_DBG+12) is reached
+ * by the process's current log_level - so it can be switched on live, per
+ * process, via the MI log_level command. Off-cost: one integer compare. */
+extern int reactor_check;
+
 #define check_io_data() \
 	do { \
 		struct fd_map* _e;\
 		int _t,k;\
 		check_error = 0;\
+		if (!is_printable(reactor_check)) break;\
 		/* iterate the fd_array and check if fd_hash is properly set for each */ \
 		...walk unchanged...
 	} while(0)
-#else
-#define check_io_data() \
-	do { check_error = 0; } while(0)
-#endif

globals.h:

 extern int memdump;
+extern int reactor_check;

globals.c, beside memlog/memdump:

 int memlog = L_DBG + 11;
 int memdump = L_DBG + 10;
+/* log level at which io_wait.h runs the full fd-map consistency walk on
+ * every io_watch_add/del - above L_DBG so it is an explicit opt-in */
+int reactor_check = L_DBG + 12;

cfg.lex:

 MEMDUMP		"memdump"|"mem_dump"
+REACTOR_CHECK	"reactor_check"
 ...
 <INITIAL>{MEMDUMP}		{ count(); yylval.strval=yytext; return MEMDUMP; }
+<INITIAL>{REACTOR_CHECK}	{ count(); yylval.strval=yytext; return REACTOR_CHECK; }

cfg.y, the memdump rule verbatim:

 %token MEMDUMP
+%token REACTOR_CHECK
 ...
 		| MEMDUMP EQUAL error { yyerror("int value expected"); }
+		| REACTOR_CHECK EQUAL snumber { IFOR(); reactor_check=$3; }
+		| REACTOR_CHECK EQUAL error { yyerror("int value expected"); }

docs/manual/Script-CoreParameters.md, in alphabetical position (before restart_persistency_cache_file), following memdump's wording:

### reactor_check

Log level at which the reactor runs a full consistency check of its fd map
on every `io_watch_add()` / `io_watch_del()` - a debugging aid for reactor
and fd-map related reports. It must be lower than or equal to the current
[log_level](#log_level) for the check to run, which also means it can be
enabled at runtime on a single process via the MI `log_level` command.

The check walks every one of the reactor's `open_files_limit` entries per
call, so it is expensive on large reactors under heavy async traffic
(measured: ~0.6 ms per call on a 21k-entry reactor; ~1,500 async
operations/s cost 13.6% of host CPU and dropped UDP under load). Keep it
disabled in production.

Default value is `16` (`L_DBG + 12`), which effectively disables the check
because it is above the normal debug log level.

Example of usage:
```opensips

    reactor_check = 2

```

Use: reactor_check = 2 in the config enables it everywhere from startup; opensips-cli -x mi log_level 16 <pid> enables it live on one worker, and setting the level back disables it again.

Option 2 — reactor_fd_check, a plain boolean

Definition: a core boolean parameter. The fd-map consistency walk in check_io_data() runs on every io_watch_add()/io_watch_del() when it is true, never when false. Default false; true by default in EXTRA_DEBUG builds, so debug builds keep today's behaviour. Set in the config, applied at startup — changing it needs a restart. Same five files, roughly the same size.

io_wait.h — the same single runtime-gated macro, with a boolean gate:

-/* ... A debugging aid, so it is one only with EXTRA_DEBUG; the plain
- * build sets check_error to 0 and moves on. */
-#ifdef EXTRA_DEBUG
+/* ... A debugging aid for reactor / fd-map reports: it runs only when the
+ * core parameter reactor_fd_check is on (default off; on by default in
+ * EXTRA_DEBUG builds) - switchable in the config, no rebuild needed.
+ * Off-cost: one global load and a branch. */
+extern int reactor_fd_check;
+
 #define check_io_data() \
 	do { \
 		struct fd_map* _e;\
 		int _t,k;\
 		check_error = 0;\
+		if (!reactor_fd_check) break;\
 		/* iterate the fd_array and check if fd_hash is properly set for each */ \
 		...walk unchanged...
 	} while(0)
-#else
-#define check_io_data() \
-	do { check_error = 0; } while(0)
-#endif

globals.h:

 extern int tcp_keepalive;
+extern int reactor_fd_check;

globals.c:

 int enable_asserts = 1;
+/* io_wait.h fd-map consistency walk on every io_watch_add/del - see the
+ * reactor_fd_check core parameter; debug builds keep it on by default */
+#ifdef EXTRA_DEBUG
+int reactor_fd_check = 1;
+#else
+int reactor_fd_check = 0;
+#endif

cfg.lex:

 TCP_KEEPALIVE           "tcp_keepalive"
+REACTOR_FD_CHECK        "reactor_fd_check"
 ...
 <INITIAL>{TCP_KEEPALIVE}       { count(); yylval.strval=yytext; return TCP_KEEPALIVE; }
+<INITIAL>{REACTOR_FD_CHECK}    { count(); yylval.strval=yytext; return REACTOR_FD_CHECK; }

cfg.y, the tcp_keepalive boolean rule verbatim:

 %token TCP_KEEPALIVE
+%token REACTOR_FD_CHECK
 ...
 		| TCP_KEEPALIVE EQUAL error { yyerror("boolean value expected"); }
+		| REACTOR_FD_CHECK EQUAL NUMBER { IFOR(); reactor_fd_check=!!$3; }
+		| REACTOR_FD_CHECK EQUAL error { yyerror("boolean value expected"); }

docs/manual/Script-CoreParameters.md, in alphabetical position (before restart_persistency_cache_file), following tcp_keepalive's wording:

### reactor_fd_check

Enables a full consistency check of the reactor's fd map on every
`io_watch_add()` / `io_watch_del()` - a debugging aid for reactor and
fd-map related reports.

The check walks every one of the reactor's `open_files_limit` entries per
call, so it is expensive on large reactors under heavy async traffic
(measured: ~0.6 ms per call on a 21k-entry reactor; ~1,500 async
operations/s cost 13.6% of host CPU and dropped UDP under load). Keep it
disabled in production and enable it only while investigating a reactor
problem; a change requires a restart.

Default value is `false` (`true` in builds with `EXTRA_DEBUG`).

Example of usage:
```opensips

    reactor_fd_check = true

```

Use: reactor_fd_check = true in the config, then restart; set it back to false and restart to disable.

The difference in one line

Option 1 can be switched on a live process without a restart; option 2 needs a restart. Both cost one compare when off, both keep the culprit-catching per-operation semantics, and both are about the same size.

[bogdan-iancu]

I don't think Option 1 is usable - in order to enable the check you need to enable full debug logging, which will simply flood your logging system. Not to mention that enabling a consistency check by changing a log level is not quite logic / intuitive :P .

Now, there is also the issue of having this new core param when comes to the backports... ideally a backport should not introduce new parameters.

But please update the PR with Option 2, with "REACTOR_DBG_FD_CHECK" (we need to underline that is a debugging option here) for the devel / 4.1 branch. And in the meanwhile we can see what to do for with the backports

[bogdan-iancu]

On a second thought, we can backport the new core param (as it is optional, for corner cases) and have it default OFF

[Lt-Flash]

Thanks Bogdan — agreed, the log-level shape would be neither intuitive nor practical.

PR updated with option 2: a boolean core parameter REACTOR_DBG_FD_CHECK, default off (on by default only in EXTRA_DEBUG builds), gating the walk at the top of check_io_data() — one global load and a branch when off, the unchanged check when on. Documented in docs/manual/Script-CoreParameters.md as a debugging-only option.

Happy to prepare the backport PRs with the parameter default off — just say which branches.

The code part of the change (the docs entry is in the commit):

diff --git a/cfg.y b/cfg.y
@@ -385,2 +385,3 @@ extern int cfg_parse_only_routes;
 %token TCP_KEEPALIVE
+%token REACTOR_DBG_FD_CHECK
 %token TCP_KEEPCOUNT
@@ -1383,2 +1384,6 @@ assign_stm: LOGLEVEL EQUAL snumber { IFOR();
 		| TCP_KEEPALIVE EQUAL error { yyerror("boolean value expected"); }
+		| REACTOR_DBG_FD_CHECK EQUAL NUMBER { IFOR();
+				reactor_dbg_fd_check=!!$3;
+				}
+		| REACTOR_DBG_FD_CHECK EQUAL error { yyerror("boolean value expected"); }
 		| TCP_MAX_MSG_TIME EQUAL NUMBER { IFOR();
diff --git a/globals.c b/globals.c
@@ -81,2 +81,8 @@ int enable_asserts = 0;
 #endif
+
+#ifdef EXTRA_DEBUG
+int reactor_dbg_fd_check = 1;
+#else
+int reactor_dbg_fd_check = 0;
+#endif
 /* abort process on failed assertion. disabled by default */
diff --git a/io_wait.h b/io_wait.h
@@ -300,2 +300,4 @@ again:
 
+extern int reactor_dbg_fd_check;
+
 #define check_io_data() \
@@ -305,2 +307,3 @@ again:
 		check_error = 0;\
+		if (!reactor_dbg_fd_check) break;\
 		/* iterate the fd_array and check if fd_hash is properly set for each */ \

[bogdan-iancu]

Thanks @Lt-Flash