Merge remote-tracking branch 'github/ticket25951'

changes/ticket25951

@@ -0,0 +1,9 @@
+  o Minor features (mainloop):
+    - Move responsibility for
+      flushing log callbacks
+      from a once-per-second callback to a callback that is only scheduled as
+      needed.  Once enough items are removed from our once-per-second
+      callback, we can eliminate it entirely to conserve CPU when idle.
+      Closes ticket
+      25951.
+

src/common/log.c

@@ -170,6 +170,9 @@ typedef struct pending_log_message_t {
 /** Log messages waiting to be replayed onto callback-based logs */
 static smartlist_t *pending_cb_messages = NULL;
 
+/** Callback to invoke when pending_cb_messages becomes nonempty. */
+static pending_callback_callback pending_cb_cb = NULL;
+
 /** Log messages waiting to be replayed once the logging system is initialized.
  */
 static smartlist_t *pending_startup_messages = NULL;
@@ -538,6 +541,9 @@ logfile_deliver(logfile_t *lf, const char *buf, size_t msg_len,
         smartlist_add(pending_cb_messages,
             pending_log_message_new(severity,domain,NULL,msg_after_prefix));
         *callbacks_deferred = 1;
+        if (smartlist_len(pending_cb_messages) == 1 && pending_cb_cb) {
+          pending_cb_cb();
+        }
       }
     } else {
       lf->callback(severity, domain, msg_after_prefix);
@@ -825,6 +831,7 @@ logs_free_all(void)
   logfiles = NULL;
   messages = pending_cb_messages;
   pending_cb_messages = NULL;
+  pending_cb_cb = NULL;
   messages2 = pending_startup_messages;
   pending_startup_messages = NULL;
   UNLOCK_LOGS();
@@ -987,6 +994,24 @@ add_temp_log(int min_severity)
   UNLOCK_LOGS();
 }
 
+/**
+ * Register "cb" as the callback to call when there are new pending log
+ * callbacks to be flushed with flush_pending_log_callbacks().
+ *
+ * Note that this callback, if present, can be invoked from any thread.
+ *
+ * This callback must not log.
+ *
+ * It is intentional that this function contains the name "callback" twice: it
+ * sets a "callback" to be called on the condition that there is a "pending
+ * callback".
+ **/
+void
+logs_set_pending_callback_callback(pending_callback_callback cb)
+{
+  pending_cb_cb = cb;
+}
+
 /**
  * Add a log handler to send messages in <b>severity</b>
  * to the function <b>cb</b>.

src/common/torlog.h

@@ -154,6 +154,8 @@ int add_android_log(const log_severity_list_t *severity,
                     const char *android_identity_tag);
 #endif // HAVE_ANDROID_LOG_H.
 int add_callback_log(const log_severity_list_t *severity, log_callback cb);
+typedef void (*pending_callback_callback)(void);
+void logs_set_pending_callback_callback(pending_callback_callback cb);
 void logs_set_domain_logging(int enabled);
 int get_min_log_level(void);
 void switch_logs_debug(void);

src/or/config.c

@@ -1552,6 +1552,7 @@ options_act_reversible(const or_options_t *old_options, char **msg)
       tor_malloc_zero(sizeof(log_severity_list_t));
     close_temp_logs();
     add_callback_log(severity, control_event_logmsg);
+    logs_set_pending_callback_callback(control_event_logmsg_pending);
     control_adjust_event_log_severity();
     tor_free(severity);
     tor_log_update_sigsafe_err_fds();

src/or/control.c

@@ -803,6 +803,9 @@ queued_event_free_(queued_event_t *ev)
 static void
 queued_events_flush_all(int force)
 {
+  /* Make sure that we get all the pending log events, if there are any. */
+  flush_pending_log_callbacks();
+
   if (PREDICT_UNLIKELY(queued_control_events == NULL)) {
     return;
   }
@@ -6186,7 +6189,7 @@ control_event_logmsg(int severity, uint32_t domain, const char *msg)
   int event;
 
   /* Don't even think of trying to add stuff to a buffer from a cpuworker
-   * thread. */
+   * thread. (See #25987 for plan to fix.) */
   if (! in_main_thread())
     return;
 
@@ -6232,6 +6235,23 @@ control_event_logmsg(int severity, uint32_t domain, const char *msg)
   }
 }
 
+/**
+ * Logging callback: called when there is a queued pending log callback.
+ */
+void
+control_event_logmsg_pending(void)
+{
+  if (! in_main_thread()) {
+    /* We can't handle this case yet, since we're using a
+     * mainloop_event_t to invoke queued_events_flush_all.  We ought to
+     * use a different mechanism instead: see #25987.
+     **/
+    return;
+  }
+  tor_assert(flush_queued_events_event);
+  mainloop_event_activate(flush_queued_events_event);
+}
+
 /** Called whenever we receive new router descriptors: tell any
  * interested control connections.  <b>routers</b> is a list of
  * routerinfo_t's.

src/or/control.h

@@ -60,6 +60,7 @@ int control_event_conn_bandwidth(connection_t *conn);
 int control_event_conn_bandwidth_used(void);
 int control_event_circuit_cell_stats(void);
 void control_event_logmsg(int severity, uint32_t domain, const char *msg);
+void control_event_logmsg_pending(void);
 int control_event_descriptors_changed(smartlist_t *routers);
 int control_event_address_mapped(const char *from, const char *to,
                                  time_t expires, const char *error,

src/or/main.c

@@ -1711,9 +1711,6 @@ run_scheduled_events(time_t now)
    */
   consider_hibernation(now);
 
-  /* 0c. If we've deferred log messages for the controller, handle them now */
-  flush_pending_log_callbacks();
-
   /* Maybe enough time elapsed for us to reconsider a circuit. */
   circuit_upgrade_circuits_from_guard_wait();