r11824@Kushana: nickm | 2007-01-03 17:15:28 -0500

 control-spec: upcase arguments in status events; note unimplemented events individually
 r11825@Kushana:  nickm | 2007-01-03 17:41:43 -0500
 Implement EXTERNAL IP server status event.
 r11826@Kushana:  nickm | 2007-01-03 17:47:10 -0500
 Implement BAD_SERVER_DESCRIPTOR server status event.
 r11827@Kushana:  nickm | 2007-01-03 18:01:56 -0500
 Implement SOCKS_UNKNOWN_PROTOCOL and DANGEROUS_SOCKS client events.
 r11828@Kushana:  nickm | 2007-01-03 18:23:22 -0500
 Implement BUG controller events. Also, flush ERR-level status events just like ERR-level log messages.
 r11829@Kushana:  nickm | 2007-01-03 23:37:27 -0500
 Yet more status events: CLOCK_SKEW, GOOD/ACCEPTED_SERVER_DESCRIPTOR, {CHECKING_}REACHABILITY_{SUCCEEDED|FAILED}
 r11833@Kushana:  nickm | 2007-01-05 16:56:37 -0500
 Note some unimplementedness in control-spec.txt


svn:r9279

8 files changed, 149 insertions, 18 deletions

diff --git a/src/or/buffers.c b/src/or/buffers.c
index eca91ae3b0..9da86e8cd4 100644
--- a/src/or/buffers.c
+++ b/src/or/buffers.c
@@ -1022,6 +1022,9 @@ fetch_from_buf_socks(buf_t *buf, socks_request_t *req,
                 "TorFAQ#SOCKSAndDNS.%s", req->port,
                 safe_socks ? " Rejecting." : "");
 //            have_warned_about_unsafe_socks = 1; // (for now, warn every time)
+            control_event_client_status(LOG_WARN,
+                          "DANGEROUS_SOCKS PROTOCOL=SOCKS5 ADDRESS=%s:%d",
+                          req->address, req->port);
             if (safe_socks)
               return -1;
           }
@@ -1125,6 +1128,9 @@ fetch_from_buf_socks(buf_t *buf, socks_request_t *req,
                  "TorFAQ#SOCKSAndDNS.%s", req->port,
                  safe_socks ? " Rejecting." : "");
 //      have_warned_about_unsafe_socks = 1; // (for now, warn every time)
+        control_event_client_status(LOG_WARN,
+                        "DANGEROUS_SOCKS PROTOCOL=SOCKS4 ADDRESS=%s:%d",
+                        tmpbuf, req->port);
         if (safe_socks)
           return -1;
       }
@@ -1200,6 +1206,13 @@ fetch_from_buf_socks(buf_t *buf, socks_request_t *req,
       log_warn(LD_APP,
                "Socks version %d not recognized. (Tor is not an http proxy.)",
                *(buf->cur));
+      {
+        char *tmp = tor_strndup(buf->cur, 8);
+        control_event_client_status(LOG_WARN,
+                                    "SOCKS_UNKNOWN_PROTOCOL DATA=\"%s\"",
+                                    escaped(tmp));
+        tor_free(tmp);
+      }
       return -1;
   }
 }
diff --git a/src/or/circuituse.c b/src/or/circuituse.c
index 8168713ec6..7c2178fd71 100644
--- a/src/or/circuituse.c
+++ b/src/or/circuituse.c
@@ -622,12 +622,17 @@ circuit_testing_opened(origin_circuit_t *circ)
 static void
 circuit_testing_failed(origin_circuit_t *circ, int at_last_hop)
 {
+  routerinfo_t *me = router_get_my_routerinfo();
   if (server_mode(get_options()) && check_whether_orport_reachable())
     return;
+  if (!me)
+    return;
 
   log_info(LD_GENERAL,
            "Our testing circuit (to see if your ORPort is reachable) "
            "has failed. I'll try again later.");
+  control_event_server_status(LOG_WARN, "REACHABILITY_FAILED ORADDRESS=%s:%d",
+                             me->address, me->or_port);
 
   /* These aren't used yet. */
   (void)circ;
diff --git a/src/or/config.c b/src/or/config.c
index e975e73801..fa3ff9641b 100644
--- a/src/or/config.c
+++ b/src/or/config.c
@@ -1801,6 +1801,7 @@ resolve_my_address(int warn_severity, or_options_t *options,
   char hostname[256];
   int explicit_ip=1;
   int explicit_hostname=1;
+  int from_interface=0;
   char tmpbuf[INET_NTOA_BUF_LEN];
   const char *address = options->Address;
   int notice_severity = warn_severity <= LOG_NOTICE ?
@@ -1843,6 +1844,7 @@ resolve_my_address(int warn_severity, or_options_t *options,
                "Could not get local interface IP address. Failing.");
         return -1;
       }
+      from_interface = 1;
       in.s_addr = htonl(interface_ip);
       tor_inet_ntoa(&in,tmpbuf,sizeof(tmpbuf));
       log_fn(notice_severity, LD_CONFIG, "Learned IP address '%s' for "
@@ -1872,6 +1874,7 @@ resolve_my_address(int warn_severity, or_options_t *options,
                  "Interface IP address '%s' is a private address too. "
                  "Ignoring.", tmpbuf);
         } else {
+          from_interface = 1;
           in.s_addr = htonl(interface_ip);
           tor_inet_ntoa(&in,tmpbuf,sizeof(tmpbuf));
           log_fn(notice_severity, LD_CONFIG,
@@ -1914,6 +1917,24 @@ resolve_my_address(int warn_severity, or_options_t *options,
     log_notice(LD_NET, "Your IP address seems to have changed. Updating.");
     ip_address_changed(0);
   }
+  if (last_resolved_addr != *addr_out) {
+    const char *method;
+    const char *h = hostname;
+    if (explicit_ip) {
+      method = "CONFIGURED";
+      h = NULL;
+    } else if (explicit_hostname) {
+      method = "RESOLVED";
+    } else if (from_interface) {
+      method = "INTERFACE";
+      h = NULL;
+    } else {
+      method = "GETHOSTNAME";
+    }
+    control_event_server_status(LOG_NOTICE,
+                                "EXTERNAL_ADDRESS ADDRESS=%s METHOD=%s %s%s",
+                                tmpbuf, method, h?"HOSTNAME=":"", h);
+  }
   last_resolved_addr = *addr_out;
   if (hostname_out)
     *hostname_out = tor_strdup(hostname);
diff --git a/src/or/control.c b/src/or/control.c
index 814a0c4e68..ea272b8686 100644
--- a/src/or/control.c
+++ b/src/or/control.c
@@ -314,7 +314,8 @@ control_adjust_event_log_severity(void)
       break;
     }
   }
-  if (EVENT_IS_INTERESTING(EVENT_LOG_OBSOLETE)) {
+  if (EVENT_IS_INTERESTING(EVENT_LOG_OBSOLETE) ||
+      EVENT_IS_INTERESTING(EVENT_STATUS_GENERAL)) {
     if (min_log_event > EVENT_NOTICE_MSG)
       min_log_event = EVENT_NOTICE_MSG;
     if (max_log_event < EVENT_ERR_MSG)
@@ -661,8 +662,17 @@ send_control1_event_string(uint16_t event, event_format_t which,
           continue;
       }
       if (control_conn->event_mask & (1<<event)) {
+        int is_err = 0;
         connection_write_to_buf(msg, strlen(msg), TO_CONN(control_conn));
         if (event == EVENT_ERR_MSG)
+          is_err = 1;
+        else if (event == EVENT_STATUS_GENERAL)
+          is_err = !strcmpstart(msg, "STATUS_GENERAL ERR ");
+        else if (event == EVENT_STATUS_CLIENT)
+          is_err = !strcmpstart(msg, "STATUS_CLIENT ERR ");
+        else if (event == EVENT_STATUS_SERVER)
+          is_err = !strcmpstart(msg, "STATUS_SERVER ERR ");
+        if (is_err)
           connection_handle_write(TO_CONN(control_conn), 1);
       }
     }
@@ -3326,14 +3336,22 @@ enable_control_logging(void)
 
 /** We got a log message: tell any interested control connections. */
 void
-control_event_logmsg(int severity, unsigned int domain, const char *msg)
+control_event_logmsg(int severity, uint32_t domain, const char *msg)
 {
   int oldlog, event;
-  (void) domain;
 
   if (disable_log_messages)
     return;
 
+  if (domain == LD_BUG && EVENT_IS_INTERESTING(EVENT_STATUS_GENERAL) &&
+      severity <= LOG_NOTICE) {
+    char *esc = esc_for_log(msg);
+    ++disable_log_messages;
+    control_event_general_status(severity, "BUG REASON=\"%s\"", esc);
+    --disable_log_messages;
+    tor_free(esc);
+  }
+
   oldlog = EVENT_IS_INTERESTING0(EVENT_LOG_OBSOLETE) &&
     (severity == LOG_NOTICE || severity == LOG_WARN || severity == LOG_ERR);
   event = log_severity_to_event(severity);
diff --git a/src/or/directory.c b/src/or/directory.c
index c4a06f448a..d062ce5942 100644
--- a/src/or/directory.c
+++ b/src/or/directory.c
@@ -117,6 +117,8 @@ directory_post_to_dirservers(uint8_t purpose, const char *payload,
       if (!post_to_hidserv_only &&
           !(ds->is_v1_authority || ds->is_v2_authority))
         continue;
+      if (purpose == DIR_PURPOSE_UPLOAD_DIR)
+        ds->has_accepted_serverdesc = 0;
       post_via_tor = purpose_is_private(purpose) ||
               !fascist_firewall_allows_address_dir(ds->addr, ds->dir_port);
       directory_initiate_command_routerstatus(rs, purpose, post_via_tor,
@@ -286,6 +288,22 @@ directory_initiate_command_routerstatus(routerstatus_t *status,
                              payload, payload_len);
 }
 
+/** DOCDOC */
+static int
+directory_conn_is_self_reachability_test(dir_connection_t *conn)
+{
+  if (conn->requested_resource &&
+      !strcmpstart(conn->requested_resource,"authority")) {
+    routerinfo_t *me = router_get_my_routerinfo();
+    if (me &&
+        router_digest_is_me(conn->identity_digest) &&
+        me->addr == conn->_base.addr &&
+        me->dir_port == conn->_base.port)
+      return 1;
+  }
+  return 0;
+}
+
 /** Called when we are unable to complete the client's request to a directory
  * server due to a network error: Mark the router as down and try again if
  * possible.
@@ -302,6 +320,14 @@ connection_dir_request_failed(dir_connection_t *conn)
              conn->_base.address, conn->_base.port);
     directory_get_from_dirserver(conn->_base.purpose, NULL,
                                  0 /* don't retry_if_no_servers */);
+
+    if (directory_conn_is_self_reachability_test(conn)) {
+      routerinfo_t *me = router_get_my_routerinfo();
+      if (me)
+        control_event_server_status(LOG_WARN,
+                                    "REACHABILITY_FAILED DIRADDRESS=%s:%d",
+                                    me->address, me->dir_port);
+    }
   } else if (conn->_base.purpose == DIR_PURPOSE_FETCH_NETWORKSTATUS) {
     log_info(LD_DIR, "Giving up on directory server at '%s'; retrying",
              conn->_base.address);
@@ -920,8 +946,8 @@ connection_dir_client_reached_eof(dir_connection_t *conn)
     now = time(NULL);
     delta = now-date_header;
     if (abs(delta)>ALLOW_DIRECTORY_TIME_SKEW) {
-      log_fn(router_digest_is_trusted_dir(conn->identity_digest) ?
-                                                        LOG_WARN : LOG_INFO,
+      int trusted = router_digest_is_trusted_dir(conn->identity_digest);
+      log_fn(trusted ? LOG_WARN : LOG_INFO,
              LD_HTTP,
              "Received directory with skewed time (server '%s:%d'): "
              "we are %d minutes %s, or the directory is %d minutes %s.",
@@ -929,6 +955,9 @@ connection_dir_client_reached_eof(dir_connection_t *conn)
              abs(delta)/60, delta>0 ? "ahead" : "behind",
              abs(delta)/60, delta>0 ? "behind" : "ahead");
       skewed = 1; /* don't check the recommended-versions line */
+      control_event_general_status(trusted ? LOG_WARN : LOG_NOTICE,
+                               "CLOCK_SKEW SKEW=%d SOURCE=DIRSERV:%s:%d",
+                               delta, conn->_base.address, conn->_base.port);
     } else {
       log_debug(LD_HTTP, "Time on received directory is within tolerance; "
                 "we are %d seconds skewed.  (That's okay.)", delta);
@@ -1173,28 +1202,43 @@ connection_dir_client_reached_eof(dir_connection_t *conn)
       SMARTLIST_FOREACH(which, char *, cp, tor_free(cp));
       smartlist_free(which);
     }
-    if (conn->requested_resource &&
-        !strcmpstart(conn->requested_resource,"authority")) {
-      /* this might have been a dirport reachability test. see if it is. */
-      routerinfo_t *me = router_get_my_routerinfo();
-      if (me &&
-          router_digest_is_me(conn->identity_digest) &&
-          me->addr == conn->_base.addr &&
-          me->dir_port == conn->_base.port)
-        router_dirport_found_reachable();
-    }
+    if (directory_conn_is_self_reachability_test(conn))
+      router_dirport_found_reachable();
   }
 
   if (conn->_base.purpose == DIR_PURPOSE_UPLOAD_DIR) {
     switch (status_code) {
-      case 200:
-        log_info(LD_GENERAL,"eof (status 200) after uploading server "
-                 "descriptor: finished.");
+      case 200: {
+          int all_done = 1;
+          trusted_dir_server_t *ds =
+            router_get_trusteddirserver_by_digest(conn->identity_digest);
+          smartlist_t *servers;
+          log_info(LD_GENERAL,"eof (status 200) after uploading server "
+                   "descriptor: finished.");
+          control_event_server_status(
+                      LOG_NOTICE, "ACCEPTED_SERVER_DESCRIPTOR DIRAUTH=%s:%d",
+                      conn->_base.address, conn->_base.port);
+
+          ds->has_accepted_serverdesc = 1;
+          servers = router_get_trusted_dir_servers();
+          SMARTLIST_FOREACH(servers, trusted_dir_server_t *, d, {
+              if ((d->is_v1_authority || d->is_v2_authority) &&
+                  !d->has_accepted_serverdesc) {
+                all_done = 0;
+                break;
+              }
+            });
+          if (all_done)
+            control_event_server_status(LOG_NOTICE, "GOOD_SERVER_DESCRIPTOR");
+        }
         break;
       case 400:
         log_warn(LD_GENERAL,"http status 400 (%s) response from "
                  "dirserver '%s:%d'. Please correct.",
                  escaped(reason), conn->_base.address, conn->_base.port);
+        control_event_server_status(LOG_WARN,
+                      "BAD_SERVER_DESCRIPTOR DIRAUTH=%s:%d REASON=\"%s\"",
+                      conn->_base.address, conn->_base.port, escaped(reason));
         break;
       case 403:
         log_warn(LD_GENERAL,
@@ -1204,6 +1248,9 @@ connection_dir_client_reached_eof(dir_connection_t *conn)
              "private IP address? See http://tor.eff.org/doc/"
              "tor-doc-server.html",escaped(reason), conn->_base.address,
              conn->_base.port);
+        control_event_server_status(LOG_WARN,
+                      "BAD_SERVER_DESCRIPTOR DIRAUTH=%s:%d REASON=\"%s\"",
+                      conn->_base.address, conn->_base.port, escaped(reason));
         break;
       default:
         log_warn(LD_GENERAL,
diff --git a/src/or/or.h b/src/or/or.h
index 08f7aed5bd..b4d2d8c51d 100644
--- a/src/or/or.h
+++ b/src/or/or.h
@@ -2717,6 +2717,9 @@ typedef struct trusted_dir_server_t {
   unsigned int is_v2_authority:1;
   /** True iff this server is an authority for hidden services. */
   unsigned int is_hidserv_authority:1;
+  /** True iff this server has accepted the most recent server descriptor
+   * we tried to upload to it. */
+  unsigned int has_accepted_serverdesc:1;
 
   int n_networkstatus_failures; /**< How many times have we asked for this
                                  * server's network-status unsuccessfully? */
diff --git a/src/or/router.c b/src/or/router.c
index d8188dcfdf..b9b5151b91 100644
--- a/src/or/router.c
+++ b/src/or/router.c
@@ -457,6 +457,9 @@ consider_testing_reachability(int test_or, int test_dir)
              !orport_reachable ? "reachability" : "bandwidth",
              me->address, me->or_port);
     circuit_launch_by_router(CIRCUIT_PURPOSE_TESTING, 0, me, 0, 1, 1);
+    control_event_server_status(LOG_NOTICE,
+                                "CHECKING_REACHABILITY ORADDRESS=%s:%d",
+                                me->address, me->or_port);
   }
 
   if (test_dir && !check_whether_dirport_reachable() &&
@@ -466,6 +469,9 @@ consider_testing_reachability(int test_or, int test_dir)
     /* ask myself, via tor, for my server descriptor. */
     directory_initiate_command_router(me, DIR_PURPOSE_FETCH_SERVERDESC,
                                       1, "authority", NULL, 0);
+    control_event_server_status(LOG_NOTICE,
+                                "CHECKING_REACHABILITY DIRADDRESS=%s:%d",
+                                me->address, me->dir_port);
   }
 }
 
@@ -474,12 +480,18 @@ void
 router_orport_found_reachable(void)
 {
   if (!can_reach_or_port) {
+    routerinfo_t *me = router_get_my_routerinfo();
     log_notice(LD_OR,"Self-testing indicates your ORPort is reachable from "
                "the outside. Excellent.%s",
                get_options()->PublishServerDescriptor ?
                  " Publishing server descriptor." : "");
     can_reach_or_port = 1;
     mark_my_descriptor_dirty();
+    if (!me)
+      return;
+    control_event_server_status(LOG_NOTICE,
+                                "REACHABILITY_SUCCEEDED ORADDRESS=%s:%d",
+                                me->address, me->dir_port);
   }
 }
 
@@ -488,10 +500,16 @@ void
 router_dirport_found_reachable(void)
 {
   if (!can_reach_dir_port) {
+    routerinfo_t *me = router_get_my_routerinfo();
     log_notice(LD_DIRSERV,"Self-testing indicates your DirPort is reachable "
                "from the outside. Excellent.");
     can_reach_dir_port = 1;
     mark_my_descriptor_dirty();
+    if (!me)
+      return;
+    control_event_server_status(LOG_NOTICE,
+                                "REACHABILITY_SUCCEEDED DIRADDRESS=%s:%d",
+                                me->address, me->dir_port);
   }
 }
 
@@ -1034,6 +1052,9 @@ router_new_address_suggestion(const char *suggestion)
    * us an answer different from what we had the last time we managed to
    * resolve it. */
   if (last_guessed_ip != addr) {
+    control_event_server_status(LOG_NOTICE,
+                                "EXTERNAL_ADDRESS ADDRESS=%s METHOD=DIRSERV",
+                                suggestion);
     log_addr_has_changed(LOG_NOTICE, last_guessed_ip, addr);
     ip_address_changed(0);
     last_guessed_ip = addr; /* router_rebuild_descriptor() will fetch it */
diff --git a/src/or/routerlist.c b/src/or/routerlist.c
index 3b99c3e7ef..c35595df50 100644
--- a/src/or/routerlist.c
+++ b/src/or/routerlist.c
@@ -2346,6 +2346,9 @@ router_set_networkstatus(const char *s, time_t arrived_at,
              "(%s GMT). Somebody is skewed here: check your clock. "
              "Not caching.",
              source_desc, published);
+    control_event_general_status(LOG_WARN,
+                                 "CLOCK_SKEW SOURCE=NETWORKSTATUS:%s:%d",
+                                 ns->source_address, ns->source_dirport);
     skewed = 1;
   }