[tor-commits] [tor/master] Use K/V parser to handle LOG messages for pluggable transports.
nickm at torproject.org
nickm at torproject.org
Thu Dec 20 21:42:40 UTC 2018
commit 426c52b377057dc5f4428c664ee56ca77d648c9e
Author: Alexander Færøy <ahf at torproject.org>
Date: Thu Dec 20 02:10:42 2018 +0100
Use K/V parser to handle LOG messages for pluggable transports.
This patch changes the LOG pluggable transport message to use the recent
K/V parser that landed in Tor. This allows PT's to specify the log
severity level as well as the message. A mapping between the PT log
severity levels and Tor's log serverity level is provided.
See: https://bugs.torproject.org/28846
---
src/feature/client/transports.c | 80 ++++++++++++++++++++++++++++++++++++++---
src/feature/client/transports.h | 2 ++
src/feature/control/control.c | 11 +++---
src/feature/control/control.h | 2 +-
src/test/test_pt.c | 29 +++++++++++----
5 files changed, 106 insertions(+), 18 deletions(-)
diff --git a/src/feature/client/transports.c b/src/feature/client/transports.c
index de53fe346..6a3479a47 100644
--- a/src/feature/client/transports.c
+++ b/src/feature/client/transports.c
@@ -101,6 +101,8 @@
#include "core/or/connection_or.h"
#include "feature/relay/ext_orport.h"
#include "feature/control/control.h"
+#include "lib/encoding/confline.h"
+#include "lib/encoding/kvline.h"
#include "lib/process/process.h"
#include "lib/process/env.h"
@@ -1144,22 +1146,63 @@ parse_log_line(const char *line, managed_proxy_t *mp)
tor_assert(line);
tor_assert(mp);
+ config_line_t *values = NULL;
+ char *log_message = NULL;
+
if (strlen(line) < (strlen(PROTO_LOG) + 1)) {
log_warn(LD_PT, "Managed proxy sent us a %s line "
"with missing argument.", PROTO_LOG);
goto done;
}
- const char *message = line + strlen(PROTO_LOG) + 1;
+ const char *data = line + strlen(PROTO_LOG) + 1;
+ values = kvline_parse(data, KV_QUOTED);
+
+ if (! values) {
+ log_warn(LD_PT, "Managed proxy \"%s\" wrote an invalid LOG message: %s",
+ mp->argv[0], data);
+ goto done;
+ }
+
+ const config_line_t *severity = config_line_find(values, "SEVERITY");
+ const config_line_t *message = config_line_find(values, "MESSAGE");
+
+ /* Check if we got a message. */
+ if (! message) {
+ log_warn(LD_PT, "Managed proxy \"%s\" wrote a LOG line without "
+ "MESSAGE: %s", mp->argv[0], data);
+ goto done;
+ }
+
+ /* Check if severity is there and whether it's valid. */
+ if (! severity) {
+ log_warn(LD_PT, "Managed proxy \"%s\" wrote a LOG line without "
+ "SEVERITY: %s", mp->argv[0], data);
+ goto done;
+ }
- log_info(LD_PT, "Managed proxy \"%s\" says: %s",
- mp->argv[0], message);
+ int log_severity = managed_proxy_severity_parse(severity->value);
+
+ if (log_severity == -1) {
+ log_warn(LD_PT, "Managed proxy \"%s\" wrote a LOG line with an "
+ "invalid severity level: %s",
+ mp->argv[0], severity->value);
+ goto done;
+ }
+
+ tor_log(log_severity, LD_PT, "Managed proxy \"%s\": %s",
+ mp->argv[0], message->value);
+
+ /* Prepend the PT name. */
+ config_line_prepend(&values, "PT", mp->argv[0]);
+ log_message = kvline_encode(values, KV_QUOTED);
/* Emit control port event. */
- control_event_pt_log(mp->argv[0], message);
+ control_event_pt_log(log_message);
done:
- return;
+ config_free_lines(values);
+ tor_free(log_message);
}
/** Return a newly allocated string that tor should place in
@@ -1779,3 +1822,30 @@ managed_proxy_exit_callback(process_t *process, process_exit_code_t exit_code)
return true;
}
+
+/** Returns a valid integer log severity level from <b>severity</b> that
+ * is compatible with Tor's logging functions. Returns <b>-1</b> on
+ * error. */
+STATIC int
+managed_proxy_severity_parse(const char *severity)
+{
+ tor_assert(severity);
+
+ /* Slightly different than log.c's parse_log_level :-( */
+ if (! strcmp(severity, "debug"))
+ return LOG_DEBUG;
+
+ if (! strcmp(severity, "info"))
+ return LOG_INFO;
+
+ if (! strcmp(severity, "notice"))
+ return LOG_NOTICE;
+
+ if (! strcmp(severity, "warning"))
+ return LOG_WARN;
+
+ if (! strcmp(severity, "error"))
+ return LOG_ERR;
+
+ return -1;
+}
diff --git a/src/feature/client/transports.h b/src/feature/client/transports.h
index a3994a009..b8d1bb008 100644
--- a/src/feature/client/transports.h
+++ b/src/feature/client/transports.h
@@ -147,6 +147,8 @@ STATIC void managed_proxy_stdout_callback(process_t *, const char *, size_t);
STATIC void managed_proxy_stderr_callback(process_t *, const char *, size_t);
STATIC bool managed_proxy_exit_callback(process_t *, process_exit_code_t);
+STATIC int managed_proxy_severity_parse(const char *);
+
#endif /* defined(PT_PRIVATE) */
#endif /* !defined(TOR_TRANSPORTS_H) */
diff --git a/src/feature/control/control.c b/src/feature/control/control.c
index 7fae3b7a1..849f11707 100644
--- a/src/feature/control/control.c
+++ b/src/feature/control/control.c
@@ -7033,15 +7033,14 @@ control_event_transport_launched(const char *mode, const char *transport_name,
mode, transport_name, fmt_addr(addr), port);
}
-/** A pluggable transport called <b>pt_name</b> has emitted a log
- * message found in <b>message</b>. */
+/** A pluggable transport called <b>pt_name</b> has emitted a log message
+ * found in <b>message</b> at <b>severity</b> log level. */
void
-control_event_pt_log(const char *pt_name, const char *message)
+control_event_pt_log(const char *log)
{
send_control_event(EVENT_PT_LOG,
- "650 PT_LOG %s %s\r\n",
- pt_name,
- message);
+ "650 PT_LOG %s\r\n",
+ log);
}
/** Convert rendezvous auth type to string for HS_DESC control events
diff --git a/src/feature/control/control.h b/src/feature/control/control.h
index a1609b0f0..b3a270767 100644
--- a/src/feature/control/control.h
+++ b/src/feature/control/control.h
@@ -207,7 +207,7 @@ 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_pt_log(const char *pt_name, const char *message);
+void control_event_pt_log(const char *log);
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,
diff --git a/src/test/test_pt.c b/src/test/test_pt.c
index 8fcdd5c1e..271d74f26 100644
--- a/src/test/test_pt.c
+++ b/src/test/test_pt.c
@@ -310,8 +310,12 @@ process_read_stdout_replacement(process_t *process, buf_t *buffer)
} else if (times_called <= 6) {
buf_add_string(buffer, "SMETHODS DONE\n");
} else if (times_called <= 7) {
- buf_add_string(buffer, "LOG Oh noes, something bad happened. "
- "What do we do!?\n");
+ buf_add_string(buffer, "LOG SEVERITY=error MESSAGE=\"Oh noes, something "
+ "bad happened. What do we do!?\"\n");
+ buf_add_string(buffer, "LOG SEVERITY=warning MESSAGE=\"warning msg\"\n");
+ buf_add_string(buffer, "LOG SEVERITY=notice MESSAGE=\"notice msg\"\n");
+ buf_add_string(buffer, "LOG SEVERITY=info MESSAGE=\"info msg\"\n");
+ buf_add_string(buffer, "LOG SEVERITY=debug MESSAGE=\"debug msg\"\n");
}
return (int)buf_datalen(buffer);
@@ -416,12 +420,25 @@ test_pt_configure_proxy(void *arg)
/* Get the log message out. */
process_notify_event_stdout(mp->process);
- tt_int_op(controlevent_n, OP_EQ, 6);
+ tt_int_op(controlevent_n, OP_EQ, 10);
tt_int_op(controlevent_event, OP_EQ, EVENT_PT_LOG);
- tt_int_op(smartlist_len(controlevent_msgs), OP_EQ, 6);
+ tt_int_op(smartlist_len(controlevent_msgs), OP_EQ, 10);
tt_str_op(smartlist_get(controlevent_msgs, 5), OP_EQ,
- "650 PT_LOG <testcase> Oh noes, something bad happened. "
- "What do we do!?\r\n");
+ "650 PT_LOG PT=<testcase> SEVERITY=error "
+ "MESSAGE=\"Oh noes, "
+ "something bad happened. What do we do!?\"\r\n");
+ tt_str_op(smartlist_get(controlevent_msgs, 6), OP_EQ,
+ "650 PT_LOG PT=<testcase> SEVERITY=warning "
+ "MESSAGE=\"warning msg\"\r\n");
+ tt_str_op(smartlist_get(controlevent_msgs, 7), OP_EQ,
+ "650 PT_LOG PT=<testcase> SEVERITY=notice "
+ "MESSAGE=\"notice msg\"\r\n");
+ tt_str_op(smartlist_get(controlevent_msgs, 8), OP_EQ,
+ "650 PT_LOG PT=<testcase> SEVERITY=info "
+ "MESSAGE=\"info msg\"\r\n");
+ tt_str_op(smartlist_get(controlevent_msgs, 9), OP_EQ,
+ "650 PT_LOG PT=<testcase> SEVERITY=debug "
+ "MESSAGE=\"debug msg\"\r\n");
{ /* check that the transport info were saved properly in the tor state */
config_line_t *transport_in_state = NULL;
More information about the tor-commits
mailing list