Add support for logging messages from pluggable transports.

This patch adds support for the "LOG" protocol message from a pluggable
transport. This allows pluggable transport developers to relay log
messages from their binary to Tor, which will both emit them as log
messages from the Tor process itself, but also pass them on via the
control port.

See: https://bugs.torproject.org/28180
See: https://bugs.torproject.org/28181
See: https://bugs.torproject.org/28182

src/feature/client/transports.c

@@ -128,6 +128,7 @@ static void parse_method_error(const char *line, int is_server_method);
 #define PROTO_SMETHODS_DONE "SMETHODS DONE"
 #define PROTO_PROXY_DONE "PROXY DONE"
 #define PROTO_PROXY_ERROR "PROXY-ERROR"
+#define PROTO_LOG "LOG"
 
 /** The first and only supported - at the moment - configuration
     protocol version. */
@@ -909,6 +910,9 @@ handle_proxy_line(const char *line, managed_proxy_t *mp)
 
     parse_proxy_error(line);
     goto err;
+  } else if (!strcmpstart(line, PROTO_LOG)) {
+    parse_log_line(line);
+    return;
   } else if (!strcmpstart(line, SPAWN_ERROR_MESSAGE)) {
     /* managed proxy launch failed: parse error message to learn why. */
     int retval, child_state, saved_errno;
@@ -1146,6 +1150,44 @@ parse_proxy_error(const char *line)
            line+strlen(PROTO_PROXY_ERROR)+1);
 }
 
+/** Parses a LOG <b>line</b> and emit log events accordingly. */
+STATIC void
+parse_log_line(const char *line)
+{
+  smartlist_t *items = smartlist_new();
+
+  if (strlen(line) < (strlen(PROTO_LOG) + 1)) {
+    log_warn(LD_PT, "Managed proxy sent us a %s line "
+                    "with missing arguments.", PROTO_LOG);
+    goto done;
+  }
+
+  const char *arguments = line + strlen(PROTO_LOG) + 1;
+
+  /* The format is 'LOG <transport> <message>'. We accept empty messages. */
+  smartlist_split_string(items, arguments, NULL,
+                         SPLIT_SKIP_SPACE|SPLIT_IGNORE_BLANK, 2);
+
+  if (smartlist_len(items) < 2) {
+    log_warn(LD_PT, "Managed proxy sent us a %s line "
+                    "with too few arguments.", PROTO_LOG);
+    goto done;
+  }
+
+  const char *transport_name = smartlist_get(items, 0);
+  const char *message = smartlist_get(items, 1);
+
+  log_info(LD_PT, "Managed proxy transport \"%s\" says: %s",
+           transport_name, message);
+
+  /* Emit control port event. */
+  control_event_transport_log(transport_name, message);
+
+ done:
+  SMARTLIST_FOREACH(items, char *, s, tor_free(s));
+  smartlist_free(items);
+}
+
 /** Return a newly allocated string that tor should place in
  * TOR_PT_SERVER_TRANSPORT_OPTIONS while configuring the server
  * manged proxy in <b>mp</b>. Return NULL if no such options are found. */

src/feature/client/transports.h

@@ -128,6 +128,7 @@ STATIC int parse_version(const char *line, managed_proxy_t *mp);
 STATIC void parse_env_error(const char *line);
 STATIC void parse_proxy_error(const char *line);
 STATIC void handle_proxy_line(const char *line, managed_proxy_t *mp);
+STATIC void parse_log_line(const char *line);
 STATIC char *get_transport_options_for_server_proxy(const managed_proxy_t *mp);
 
 STATIC void managed_proxy_destroy(managed_proxy_t *mp,

src/feature/control/control.c

@@ -7395,6 +7395,17 @@ control_event_transport_launched(const char *mode, const char *transport_name,
                      mode, transport_name, fmt_addr(addr), port);
 }
 
+/** A pluggable transport called <b>transport_name</b> has emitted a log
+ * message found in <b>message</b>. */
+void
+control_event_transport_log(const char *transport_name, const char *message)
+{
+  send_control_event(EVENT_TRANSPORT_LOG,
+                     "650 TRANSPORT_LOG %s %s\r\n",
+                     transport_name,
+                     message);
+}
+
 /** Convert rendezvous auth type to string for HS_DESC control events
  */
 const char *

src/feature/control/control.h

@@ -205,6 +205,8 @@ void control_event_clients_seen(const char *controller_str);
 void control_event_transport_launched(const char *mode,
                                       const char *transport_name,
                                       tor_addr_t *addr, uint16_t port);
+void control_event_transport_log(const char *transport_name,
+                                 const char *message);
 const char *rend_auth_type_to_string(rend_auth_type_t auth_type);
 MOCK_DECL(const char *, node_describe_longname_by_id,(const char *id_digest));
 void control_event_hs_descriptor_requested(const char *onion_address,
@@ -293,7 +295,8 @@ void control_free_all(void);
 #define EVENT_HS_DESC                 0x0021
 #define EVENT_HS_DESC_CONTENT         0x0022
 #define EVENT_NETWORK_LIVENESS        0x0023
-#define EVENT_MAX_                    0x0023
+#define EVENT_TRANSPORT_LOG           0x0024
+#define EVENT_MAX_                    0x0024
 
 /* sizeof(control_connection_t.event_mask) in bits, currently a uint64_t */
 #define EVENT_CAPACITY_               0x0040

src/test/test_pt.c

@@ -304,11 +304,16 @@ process_read_stdout_replacement(process_t *process, buf_t *buffer)
 
   /* Generate some dummy CMETHOD lines the first 5 times. The 6th
      time, send 'CMETHODS DONE' to finish configuring the proxy. */
-  if (times_called++ != 5) {
+  times_called++;
+
+  if (times_called <= 5) {
     buf_add_printf(buffer, "SMETHOD mock%d 127.0.0.1:555%d\n",
                            times_called, times_called);
-  } else {
+  } else if (times_called <= 6) {
     buf_add_string(buffer, "SMETHODS DONE\n");
+  } else if (times_called <= 7) {
+    buf_add_string(buffer, "LOG mock3 Oh noes, something bad happened. "
+                           "What do we do!?\n");
   }
 
   return (int)buf_datalen(buffer);
@@ -410,6 +415,16 @@ test_pt_configure_proxy(void *arg)
   tt_str_op(smartlist_get(controlevent_msgs, 4), OP_EQ,
             "650 TRANSPORT_LAUNCHED server mock5 127.0.0.1 5555\r\n");
 
+  /* Get the log message out. */
+  process_notify_event_stdout(mp->process);
+
+  tt_int_op(controlevent_n, OP_EQ, 6);
+  tt_int_op(controlevent_event, OP_EQ, EVENT_TRANSPORT_LOG);
+  tt_int_op(smartlist_len(controlevent_msgs), OP_EQ, 6);
+  tt_str_op(smartlist_get(controlevent_msgs, 5), OP_EQ,
+            "650 TRANSPORT_LOG mock3 Oh noes, something bad happened. "
+            "What do we do!?\r\n");
+
   { /* check that the transport info were saved properly in the tor state */
     config_line_t *transport_in_state = NULL;
     smartlist_t *transport_info_sl = smartlist_new();