log the reason for publishing a new relay descriptor

now we have a better chance of hunting down the root cause of bug 1810.

changes/bug3252

@@ -0,0 +1,4 @@
+  o Minor features:
+    - Relays now log the reason for publishing a new relay descriptor,
+      so we have a better chance of hunting down the root cause of bug
+      1810. Resolves ticket 3252.

src/or/config.c

@@ -1459,7 +1459,7 @@ options_act(or_options_t *old_options)
    */
   if (!old_options ||
       options_transition_affects_descriptor(old_options, options))
-    mark_my_descriptor_dirty();
+    mark_my_descriptor_dirty("config change");
 
   /* We may need to reschedule some directory stuff if our status changed. */
   if (old_options) {

src/or/dns.c

@@ -1295,14 +1295,17 @@ configure_nameservers(int force)
   nameservers_configured = 1;
   if (nameserver_config_failed) {
     nameserver_config_failed = 0;
-    mark_my_descriptor_dirty();
+    /* XXX the three calls to republish the descriptor might be producing
+     * descriptors that are only cosmetically different, especially on
+     * non-exit relays! -RD */
+    mark_my_descriptor_dirty("dns resolvers back");
   }
   return 0;
  err:
   nameservers_configured = 0;
   if (! nameserver_config_failed) {
     nameserver_config_failed = 1;
-    mark_my_descriptor_dirty();
+    mark_my_descriptor_dirty("dns resolvers failed");
   }
   return -1;
 }
@@ -1522,7 +1525,7 @@ add_wildcarded_test_address(const char *address)
         "broken.", address, n);
     if (!dns_is_completely_invalid) {
       dns_is_completely_invalid = 1;
-      mark_my_descriptor_dirty();
+      mark_my_descriptor_dirty("dns hijacking confirmed");
     }
     if (!dns_wildcarded_test_address_notice_given)
       control_event_server_status(LOG_WARN, "DNS_USELESS");

src/or/main.c

@@ -1381,7 +1381,7 @@ ip_address_changed(int at_interface)
         reset_bandwidth_test();
       stats_n_seconds_working = 0;
       router_reset_reachability();
-      mark_my_descriptor_dirty();
+      mark_my_descriptor_dirty("IP address changed");
     }
   }
 

src/or/router.c

@@ -87,7 +87,7 @@ set_onion_key(crypto_pk_env_t *k)
   onionkey = k;
   onionkey_set_at = time(NULL);
   tor_mutex_release(key_lock);
-  mark_my_descriptor_dirty();
+  mark_my_descriptor_dirty("set onion key");
 }
 
 /** Return the current onion key.  Requires that the onion key has been
@@ -274,7 +274,7 @@ rotate_onion_key(void)
   now = time(NULL);
   state->LastRotatedOnionKey = onionkey_set_at = now;
   tor_mutex_release(key_lock);
-  mark_my_descriptor_dirty();
+  mark_my_descriptor_dirty("rotated onion key");
   or_state_mark_dirty(state, get_options()->AvoidDiskWrites ? now+3600 : 0);
   goto done;
  error:
@@ -908,7 +908,7 @@ router_orport_found_reachable(void)
                get_options()->_PublishServerDescriptor != NO_AUTHORITY ?
                  " Publishing server descriptor." : "");
     can_reach_or_port = 1;
-    mark_my_descriptor_dirty();
+    mark_my_descriptor_dirty("ORPort found reachable");
     control_event_server_status(LOG_NOTICE,
                                 "REACHABILITY_SUCCEEDED ORADDRESS=%s:%d",
                                 me->address, me->or_port);
@@ -925,7 +925,7 @@ router_dirport_found_reachable(void)
                "from the outside. Excellent.");
     can_reach_dir_port = 1;
     if (decide_to_advertise_dirport(get_options(), me->dir_port))
-      mark_my_descriptor_dirty();
+      mark_my_descriptor_dirty("DirPort found reachable");
     control_event_server_status(LOG_NOTICE,
                                 "REACHABILITY_SUCCEEDED DIRADDRESS=%s:%d",
                                 me->address, me->dir_port);
@@ -1232,6 +1232,10 @@ router_upload_dir_desc_to_dirservers(int force)
     return;
   if (!force && !desc_needs_upload)
     return;
+
+  log_info(LD_OR, "Uploading relay descriptor to directory authorities%s",
+           force ? " (forced)" : "");
+
   desc_needs_upload = 0;
 
   desc_len = ri->cache_info.signed_descriptor_len;
@@ -1423,6 +1427,8 @@ router_rebuild_descriptor(int force)
     return -1;
   }
 
+  log_info(LD_OR, "Rebuilding relay descriptor%s", force ? " (forced)" : "");
+
   ri = tor_malloc_zero(sizeof(routerinfo_t));
   ri->cache_info.routerlist_index = -1;
   ri->address = tor_dup_ip(addr);
@@ -1597,14 +1603,15 @@ void
 mark_my_descriptor_dirty_if_older_than(time_t when)
 {
   if (desc_clean_since < when)
-    mark_my_descriptor_dirty();
+    mark_my_descriptor_dirty("time for new descriptor");
 }
 
 /** Call when the current descriptor is out of date. */
 void
-mark_my_descriptor_dirty(void)
+mark_my_descriptor_dirty(const char *reason)
 {
   desc_clean_since = 0;
+  log_info(LD_OR, "Decided to publish new relay descriptor: %s", reason);
 }
 
 /** How frequently will we republish our descriptor because of large (factor
@@ -1629,7 +1636,7 @@ check_descriptor_bandwidth_changed(time_t now)
     if (last_changed+MAX_BANDWIDTH_CHANGE_FREQ < now) {
       log_info(LD_GENERAL,
                "Measured bandwidth has changed; rebuilding descriptor.");
-      mark_my_descriptor_dirty();
+      mark_my_descriptor_dirty("bandwidth has changed");
       last_changed = now;
     }
   }

src/or/router.h

@@ -62,7 +62,7 @@ int should_refuse_unknown_exits(or_options_t *options);
 
 void router_upload_dir_desc_to_dirservers(int force);
 void mark_my_descriptor_dirty_if_older_than(time_t when);
-void mark_my_descriptor_dirty(void);
+void mark_my_descriptor_dirty(const char *reason);
 void check_descriptor_bandwidth_changed(time_t now);
 void check_descriptor_ipaddress_changed(time_t now);
 void router_new_address_suggestion(const char *suggestion,