[PATCH 4/4] gdb: add debug prints in event loop

[Simon Marchi <simon.marchi@polymtl.ca>]

Add debug printouts about event loop-related events:

 - When a file descriptor handler gets invoked
 - When an async event/signal handler gets invoked
 - When an async event/signal handler gets marked or cleared

Since mark_async_signal_handler is meant to be used from a signal
handler, it needs to be async-signal-safe.  Therefore, we output the
debug statement "manually" using async-signal-safe methods.

Outputing messages about UI-related events is very distracting and gets
in the way of typing.  I therefore made "set debug event-loop" have
three possible values instead of just on/off: off, all-except-ui and
all.  Event sources (currently just file descriptor handlers) have a
flag indicating whether they are UI-related, so we can filter the
messages based on that.

For GDBserver, I followed the pattern of the existing "remote-debug"
flag.  Event loop debugging can be enabled using the --event-loop-debug
command line flag or the "set event-loop-debug" monitor command.  For
GDBserver, it's only a boolean switch, which toggles between off and all
messages.

gdb/ChangeLog:

	* async-event.c (mark_async_signal_handler): Add debug print.
	(clear_async_signal_handler): Likewise.
	(mark_async_event_handler): Likewise.
	(clear_async_signal_handler): Likewise.
	(invoke_async_signal_handlers): Likewise.
	(mark_async_event_handler): Likewise.
	(clear_async_event_handler): Likewise.
	(check_async_event_handlers): Likewise.
	* event-top.c (ui_register_input_event_handler): Pass true to
	add_file_handler's is_ui parameter.
	(debug_event_loop_off): New global.
	(debug_event_loop_all_except_ui): New global.
	(debug_event_loop_all): New global.
	(debug_event_loop_enum): New global.
	(debug_event_loop_value): New global.
	(set_debug_event_loop_command): New function.
	(show_debug_event_loop): New function.
	(_initialize_event_top): New function.

gdbserver/ChangeLog:

	* server.cc (monitor_show_help): Mention new command.
	(handle_monitor_command): Handle "set
	debug-event-loop".
	(gdbserver_usage): Mention new flag.
	(captured_main): Handle "--debug-event-loop".

gdbsupport/ChangeLog:

	* event-loop.h (add_file_handler): Add is_ui parameter.
	(enum class debug_event_loop_kind): New enum.
	(debug_event_loop): New variable declaration.
	(event_loop_debug_printf_1): New function declaration.
	(event_loop_debug_printf): New macro.
	* event-loop.cc (debug_event_loop): New variable.
	(struct file_handler) <is_ui>: New field.
	(create_file_handler): Add is_ui parameter.
	(add_file_handler): Likewise.
	(handle_file_event): Add debug print.
	(event_loop_debug_printf_1): New function.

Change-Id: If78ed3a69179881368e7895b42940ce13b6a1a05
---
 gdb/async-event.c        | 27 ++++++++++++++++++++-
 gdb/event-top.c          | 52 +++++++++++++++++++++++++++++++++++++++-
 gdbserver/server.cc      | 15 ++++++++++++
 gdbsupport/event-loop.cc | 38 ++++++++++++++++++++++++-----
 gdbsupport/event-loop.h  | 44 ++++++++++++++++++++++++++++++++--
 5 files changed, 166 insertions(+), 10 deletions(-)

diff --git a/gdb/async-event.c b/gdb/async-event.c
index 55be014484e5..4228dfb09e68 100644
--- a/gdb/async-event.c
+++ b/gdb/async-event.c
@@ -157,8 +157,23 @@ create_async_signal_handler (sig_handler_func * proc,
    for some event.  The caller of this function is the interrupt
    handler associated with a signal.  */
 void
-mark_async_signal_handler (async_signal_handler * async_handler_ptr)
+mark_async_signal_handler (async_signal_handler *async_handler_ptr)
 {
+  if (debug_event_loop != debug_event_loop_kind::OFF)
+    {
+      /* This is called by signal handlers, so we print it "by hand" using
+	 the async-signal-safe methods.  */
+      const char head[] = ("[event-loop] mark_async_signal_handler: marking"
+			   "async signal handler `");
+      gdb_stdlog->write_async_safe (head, strlen (head));
+
+      gdb_stdlog->write_async_safe (async_handler_ptr->name,
+				    strlen (async_handler_ptr->name));
+
+      const char tail[] = "`\n";
+      gdb_stdlog->write_async_safe (tail, strlen (tail));
+    }
+
   async_handler_ptr->ready = 1;
   serial_event_set (async_signal_handlers_serial_event);
 }
@@ -168,6 +183,8 @@ mark_async_signal_handler (async_signal_handler * async_handler_ptr)
 void
 clear_async_signal_handler (async_signal_handler *async_handler_ptr)
 {
+  event_loop_debug_printf ("clearing async signal handler `%s`",
+			   async_handler_ptr->name);
   async_handler_ptr->ready = 0;
 }
 
@@ -211,6 +228,8 @@ invoke_async_signal_handlers (void)
       /* Async signal handlers have no connection to whichever was the
 	 current UI, and thus always run on the main one.  */
       current_ui = main_ui;
+      event_loop_debug_printf ("invoking async signal handler `%s`",
+			       async_handler_ptr->name);
       (*async_handler_ptr->proc) (async_handler_ptr->client_data);
     }
 
@@ -274,6 +293,8 @@ create_async_event_handler (async_event_handler_func *proc,
 void
 mark_async_event_handler (async_event_handler *async_handler_ptr)
 {
+  event_loop_debug_printf ("marking async event handler `%s`",
+			   async_handler_ptr->name);
   async_handler_ptr->ready = 1;
 }
 
@@ -282,6 +303,8 @@ mark_async_event_handler (async_event_handler *async_handler_ptr)
 void
 clear_async_event_handler (async_event_handler *async_handler_ptr)
 {
+  event_loop_debug_printf ("clearing async event handler `%s`",
+			   async_handler_ptr->name);
   async_handler_ptr->ready = 0;
 }
 
@@ -300,6 +323,8 @@ check_async_event_handlers ()
       if (async_handler_ptr->ready)
 	{
 	  async_handler_ptr->ready = 0;
+	  event_loop_debug_printf ("invoking async event handler `%s`",
+				   async_handler_ptr->name);
 	  (*async_handler_ptr->proc) (async_handler_ptr->client_data);
 	  return 1;
 	}
diff --git a/gdb/event-top.c b/gdb/event-top.c
index fdce5de6f429..6bf7a106bc97 100644
--- a/gdb/event-top.c
+++ b/gdb/event-top.c
@@ -525,7 +525,7 @@ void
 ui_register_input_event_handler (struct ui *ui)
 {
   add_file_handler (ui->input_fd, stdin_event_handler, ui,
-		    string_printf ("ui-%d", ui->num));
+		    string_printf ("ui-%d", ui->num), true /* is_ui */);
 }
 
 /* See top.h.  */
@@ -1287,3 +1287,53 @@ gdb_disable_readline (void)
     gdb_rl_callback_handler_remove ();
   delete_file_handler (ui->input_fd);
 }
+
+static const char debug_event_loop_off[] = "off";
+static const char debug_event_loop_all_except_ui[] = "all-except-ui";
+static const char debug_event_loop_all[] = "all";
+
+static const char *debug_event_loop_enum[] = {
+  debug_event_loop_off,
+  debug_event_loop_all_except_ui,
+  debug_event_loop_all,
+  nullptr
+};
+
+static const char *debug_event_loop_value = debug_event_loop_off;
+
+static void
+set_debug_event_loop_command (const char *args, int from_tty,
+			      cmd_list_element *c)
+{
+  if (debug_event_loop_value == debug_event_loop_off)
+    debug_event_loop = debug_event_loop_kind::OFF;
+  else if (debug_event_loop_value == debug_event_loop_all_except_ui)
+    debug_event_loop = debug_event_loop_kind::ALL_EXCEPT_UI;
+  else if (debug_event_loop_value == debug_event_loop_all)
+    debug_event_loop = debug_event_loop_kind::ALL;
+  else
+    gdb_assert_not_reached ("Invalid debug event look kind value.");
+}
+
+static void
+show_debug_event_loop_command (struct ui_file *file, int from_tty,
+			       cmd_list_element *cmd, const char *value)
+{
+  fprintf_filtered (file, _("Event loop debugging is %s.\n"), value);
+}
+
+void _initialize_event_top ();
+void
+_initialize_event_top ()
+{
+  add_setshow_enum_cmd ("event-loop", class_maintenance,
+			debug_event_loop_enum,
+			&debug_event_loop_value,
+			_("Set event-loop debugging."),
+			_("Show event-loop debugging."),
+			_("\
+Control whether to show event loop-related debug messages."),
+			set_debug_event_loop_command,
+			show_debug_event_loop_command,
+			&setdebuglist, &showdebuglist);
+}
diff --git a/gdbserver/server.cc b/gdbserver/server.cc
index d45154d1f547..e6314e56506b 100644
--- a/gdbserver/server.cc
+++ b/gdbserver/server.cc
@@ -955,6 +955,8 @@ monitor_show_help (void)
   monitor_output ("    Enable h/w breakpoint/watchpoint debugging messages\n");
   monitor_output ("  set remote-debug <0|1>\n");
   monitor_output ("    Enable remote protocol debugging messages\n");
+  monitor_output ("  set event-loop-debug <0|1>\n");
+  monitor_output ("    Enable event loop debugging messages\n");
   monitor_output ("  set debug-format option1[,option2,...]\n");
   monitor_output ("    Add additional information to debugging messages\n");
   monitor_output ("    Options: all, none");
@@ -1389,6 +1391,16 @@ handle_monitor_command (char *mon, char *own_buf)
       remote_debug = 0;
       monitor_output ("Protocol debug output disabled.\n");
     }
+  else if (strcmp (mon, "set event-loop-debug 1") == 0)
+    {
+      debug_event_loop = debug_event_loop_kind::ALL;
+      monitor_output ("Event loop debug output enabled.\n");
+    }
+  else if (strcmp (mon, "set event-loop-debug 0") == 0)
+    {
+      debug_event_loop = debug_event_loop_kind::OFF;
+      monitor_output ("Event loop debug output disabled.\n");
+    }
   else if (startswith (mon, "set debug-format "))
     {
       std::string error_msg
@@ -3468,6 +3480,7 @@ gdbserver_usage (FILE *stream)
 	   "                            none\n"
 	   "                            timestamp\n"
 	   "  --remote-debug        Enable remote protocol debugging output.\n"
+	   "  --event-loop-debug    Enable event loop debugging output.\n"
 	   "  --disable-packet=OPT1[,OPT2,...]\n"
 	   "                        Disable support for RSP packets or features.\n"
 	   "                          Options:\n"
@@ -3683,6 +3696,8 @@ captured_main (int argc, char *argv[])
 	}
       else if (strcmp (*next_arg, "--remote-debug") == 0)
 	remote_debug = 1;
+      else if (strcmp (*next_arg, "--event-loop-debug") == 0)
+	debug_event_loop = debug_event_loop_kind::ALL;
       else if (startswith (*next_arg, "--debug-file="))
 	debug_set_output ((*next_arg) + sizeof ("--debug-file=") -1);
       else if (strcmp (*next_arg, "--disable-packet") == 0)
diff --git a/gdbsupport/event-loop.cc b/gdbsupport/event-loop.cc
index 0d78122e0cc3..94941580d6ab 100644
--- a/gdbsupport/event-loop.cc
+++ b/gdbsupport/event-loop.cc
@@ -34,6 +34,10 @@
 #include "gdbsupport/gdb_sys_time.h"
 #include "gdbsupport/gdb_select.h"
 
+/* See event-loop.h.  */
+
+debug_event_loop_kind debug_event_loop;
+
 /* Tell create_file_handler what events we are interested in.
    This is used by the select version of the event loop.  */
 
@@ -64,6 +68,9 @@ struct file_handler
   /* User-friendly name of this handler.  Heap-allocated, owned by this.*/
   std::string *name;
 
+  /* If set, this file descriptor is used for a user interface.  */
+  bool is_ui;
+
   /* Was an error detected on this fd?  */
   int error;
 
@@ -164,7 +171,7 @@ timer_list;
 
 static void create_file_handler (int fd, int mask, handler_func *proc,
 				 gdb_client_data client_data,
-				 std::string &&name);
+				 std::string &&name, bool is_ui);
 static int gdb_wait_for_event (int);
 static int update_wait_timeout (void);
 static int poll_timers (void);
@@ -239,7 +246,7 @@ gdb_do_one_event (void)
 
 void
 add_file_handler (int fd, handler_func *proc, gdb_client_data client_data,
-		  std::string &&name)
+		  std::string &&name, bool is_ui)
 {
 #ifdef HAVE_POLL
   struct pollfd fds;
@@ -265,7 +272,8 @@ add_file_handler (int fd, handler_func *proc, gdb_client_data client_data,
   if (use_poll)
     {
 #ifdef HAVE_POLL
-      create_file_handler (fd, POLLIN, proc, client_data, std::move (name));
+      create_file_handler (fd, POLLIN, proc, client_data, std::move (name),
+			   is_ui);
 #else
       internal_error (__FILE__, __LINE__,
 		      _("use_poll without HAVE_POLL"));
@@ -273,7 +281,7 @@ add_file_handler (int fd, handler_func *proc, gdb_client_data client_data,
     }
   else
     create_file_handler (fd, GDB_READABLE | GDB_EXCEPTION,
-			 proc, client_data, std::move (name));
+			 proc, client_data, std::move (name), is_ui);
 }
 
 /* Helper for add_file_handler.
@@ -289,7 +297,8 @@ add_file_handler (int fd, handler_func *proc, gdb_client_data client_data,
 
 static void
 create_file_handler (int fd, int mask, handler_func * proc,
-		     gdb_client_data client_data, std::string &&name)
+		     gdb_client_data client_data, std::string &&name,
+		     bool is_ui)
 {
   file_handler *file_ptr;
 
@@ -358,6 +367,7 @@ create_file_handler (int fd, int mask, handler_func * proc,
   file_ptr->client_data = client_data;
   file_ptr->mask = mask;
   file_ptr->name = new std::string (std::move (name));
+  file_ptr->is_ui = is_ui;
 }
 
 /* Return the next file handler to handle, and advance to the next
@@ -558,7 +568,12 @@ handle_file_event (file_handler *file_ptr, int ready_mask)
 
 	  /* If there was a match, then call the handler.  */
 	  if (mask != 0)
-	    (*file_ptr->proc) (file_ptr->error, file_ptr->client_data);
+	    {
+	      event_loop_ui_debug_printf (file_ptr->is_ui,
+					  "invoking fd file handler `%s`",
+					  file_ptr->name->c_str ());
+	      file_ptr->proc (file_ptr->error, file_ptr->client_data);
+	    }
 	}
     }
 }
@@ -897,3 +912,14 @@ poll_timers (void)
 
   return 0;
 }
+
+/* See event-loop.h.  */
+
+void
+event_loop_debug_printf_1 (const char *func_name, const char *fmt, ...)
+{
+  va_list args;
+  va_start (args, fmt);
+  debug_prefixed_vprintf ("event-loop", func_name, fmt, args);
+  va_end (args);
+}
diff --git a/gdbsupport/event-loop.h b/gdbsupport/event-loop.h
index d7478b037a9c..c29d6a861236 100644
--- a/gdbsupport/event-loop.h
+++ b/gdbsupport/event-loop.h
@@ -84,11 +84,13 @@ extern void delete_file_handler (int fd);
 
    FD is the file descriptor for the file/stream to be listened to.
 
-   NAME is a user-friendly name for the handler.  */
+   NAME is a user-friendly name for the handler.
+
+   If IS_UI is set, this file descriptor is used for a user interface.  */
 
 extern void add_file_handler (int fd, handler_func *proc,
 			      gdb_client_data client_data,
-			      std::string &&name);
+			      std::string &&name, bool is_ui = false);
 
 extern int create_timer (int milliseconds, 
 			 timer_handler_func *proc, 
@@ -109,4 +111,42 @@ extern int invoke_async_signal_handlers ();
 
 extern int check_async_event_handlers ();
 
+enum class debug_event_loop_kind
+{
+  OFF,
+
+  /* Print all event-loop related messages, except events from user-interface
+     event sources.  */
+  ALL_EXCEPT_UI,
+
+  /* Print all event-loop related messages.  */
+  ALL,
+};
+
+/* True if we are printing event loop debug statements.  */
+extern debug_event_loop_kind debug_event_loop;
+
+/* Print an "event loop" debug statement.  Should be used through
+   event_loop_debug_printf.  */
+void ATTRIBUTE_PRINTF (2, 3) event_loop_debug_printf_1
+  (const char *func_name, const char *fmt, ...);
+
+#define event_loop_debug_printf(fmt, ...) \
+  do \
+    { \
+      if (debug_event_loop != debug_event_loop_kind::OFF) \
+	event_loop_debug_printf_1 (__func__, fmt, ##__VA_ARGS__); \
+    } \
+  while (0)
+
+#define event_loop_ui_debug_printf(is_ui, fmt, ...) \
+  do \
+    { \
+      if (debug_event_loop == debug_event_loop_kind::ALL \
+	  || (debug_event_loop == debug_event_loop_kind::ALL_EXCEPT_UI \
+	      && !is_ui)) \
+	event_loop_debug_printf_1 (__func__, fmt, ##__VA_ARGS__); \
+    } \
+  while (0)
+
 #endif /* EVENT_LOOP_H */
-- 
2.28.0