control_events.c (75130B)
1 /* Copyright (c) 2004-2006, Roger Dingledine, Nick Mathewson. 2 * Copyright (c) 2007-2024, The Tor Project, Inc. */ 3 /* See LICENSE for licensing information */ 4 5 /** 6 * \file control_events.c 7 * \brief Implement the event-reporting part of the controller API. 8 **/ 9 10 #define CONTROL_MODULE_PRIVATE 11 #define CONTROL_EVENTS_PRIVATE 12 #define OCIRC_EVENT_PRIVATE 13 14 #include "core/or/or.h" 15 #include "app/config/config.h" 16 #include "core/mainloop/connection.h" 17 #include "core/mainloop/mainloop.h" 18 #include "core/or/channeltls.h" 19 #include "core/or/circuitlist.h" 20 #include "core/or/circuitstats.h" 21 #include "core/or/command.h" 22 #include "core/or/connection_edge.h" 23 #include "core/or/connection_or.h" 24 #include "core/or/congestion_control_common.h" 25 #include "core/or/reasons.h" 26 #include "feature/control/control.h" 27 #include "feature/control/control_events.h" 28 #include "feature/control/control_fmt.h" 29 #include "feature/control/control_proto.h" 30 #include "feature/dircommon/directory.h" 31 #include "feature/nodelist/describe.h" 32 #include "feature/nodelist/networkstatus.h" 33 #include "feature/nodelist/nodelist.h" 34 35 #include "feature/control/control_connection_st.h" 36 #include "core/or/entry_connection_st.h" 37 #include "feature/nodelist/networkstatus_st.h" 38 #include "core/or/or_connection_st.h" 39 #include "core/or/or_circuit_st.h" 40 #include "core/or/origin_circuit_st.h" 41 42 #include "lib/evloop/compat_libevent.h" 43 #include "lib/encoding/confline.h" 44 45 static void flush_queued_events_cb(mainloop_event_t *event, void *arg); 46 static void control_get_bytes_rw_last_sec(uint64_t *r, uint64_t *w); 47 48 /** Yield true iff <b>s</b> is the state of a control_connection_t that has 49 * finished authentication and is accepting commands. */ 50 #define STATE_IS_OPEN(s) ((s) == CONTROL_CONN_STATE_OPEN) 51 52 /** An event mask of all the events that any controller is interested in 53 * receiving. */ 54 static event_mask_t global_event_mask = 0; 55 56 /** True iff we have disabled log messages from being sent to the controller */ 57 static int disable_log_messages = 0; 58 59 /** Macro: true if any control connection is interested in events of type 60 * <b>e</b>. */ 61 #define EVENT_IS_INTERESTING(e) \ 62 (!! (global_event_mask & EVENT_MASK_(e))) 63 64 /** Macro: true if any event from the bitfield 'e' is interesting. */ 65 #define ANY_EVENT_IS_INTERESTING(e) \ 66 (!! (global_event_mask & (e))) 67 68 static void send_control_event_impl(uint16_t event, 69 const char *format, va_list ap) 70 CHECK_PRINTF(2,0); 71 static int control_event_status(int type, int severity, const char *format, 72 va_list args) 73 CHECK_PRINTF(3,0); 74 75 static void send_control_event(uint16_t event, 76 const char *format, ...) 77 CHECK_PRINTF(2,3); 78 79 /** Table mapping event values to their names. Used to implement SETEVENTS 80 * and GETINFO events/names, and to keep they in sync. */ 81 const struct control_event_t control_event_table[] = { 82 { EVENT_CIRCUIT_STATUS, "CIRC" }, 83 { EVENT_CIRCUIT_STATUS_MINOR, "CIRC_MINOR" }, 84 { EVENT_STREAM_STATUS, "STREAM" }, 85 { EVENT_OR_CONN_STATUS, "ORCONN" }, 86 { EVENT_BANDWIDTH_USED, "BW" }, 87 { EVENT_DEBUG_MSG, "DEBUG" }, 88 { EVENT_INFO_MSG, "INFO" }, 89 { EVENT_NOTICE_MSG, "NOTICE" }, 90 { EVENT_WARN_MSG, "WARN" }, 91 { EVENT_ERR_MSG, "ERR" }, 92 { EVENT_NEW_DESC, "NEWDESC" }, 93 { EVENT_ADDRMAP, "ADDRMAP" }, 94 { EVENT_DESCCHANGED, "DESCCHANGED" }, 95 { EVENT_NS, "NS" }, 96 { EVENT_STATUS_GENERAL, "STATUS_GENERAL" }, 97 { EVENT_STATUS_CLIENT, "STATUS_CLIENT" }, 98 { EVENT_STATUS_SERVER, "STATUS_SERVER" }, 99 { EVENT_GUARD, "GUARD" }, 100 { EVENT_STREAM_BANDWIDTH_USED, "STREAM_BW" }, 101 { EVENT_CLIENTS_SEEN, "CLIENTS_SEEN" }, 102 { EVENT_NEWCONSENSUS, "NEWCONSENSUS" }, 103 { EVENT_BUILDTIMEOUT_SET, "BUILDTIMEOUT_SET" }, 104 { EVENT_GOT_SIGNAL, "SIGNAL" }, 105 { EVENT_CONF_CHANGED, "CONF_CHANGED"}, 106 { EVENT_CONN_BW, "CONN_BW" }, 107 { EVENT_CELL_STATS, "CELL_STATS" }, 108 { EVENT_CIRC_BANDWIDTH_USED, "CIRC_BW" }, 109 { EVENT_TRANSPORT_LAUNCHED, "TRANSPORT_LAUNCHED" }, 110 { EVENT_HS_DESC, "HS_DESC" }, 111 { EVENT_HS_DESC_CONTENT, "HS_DESC_CONTENT" }, 112 { EVENT_NETWORK_LIVENESS, "NETWORK_LIVENESS" }, 113 { 0, NULL }, 114 }; 115 116 /** Given a log severity, return the corresponding control event code. */ 117 static inline int 118 log_severity_to_event(int severity) 119 { 120 switch (severity) { 121 case LOG_DEBUG: return EVENT_DEBUG_MSG; 122 case LOG_INFO: return EVENT_INFO_MSG; 123 case LOG_NOTICE: return EVENT_NOTICE_MSG; 124 case LOG_WARN: return EVENT_WARN_MSG; 125 case LOG_ERR: return EVENT_ERR_MSG; 126 default: return -1; 127 } 128 } 129 130 /** Helper: clear bandwidth counters of all origin circuits. */ 131 static void 132 clear_circ_bw_fields(void) 133 { 134 origin_circuit_t *ocirc; 135 SMARTLIST_FOREACH_BEGIN(circuit_get_global_list(), circuit_t *, circ) { 136 if (!CIRCUIT_IS_ORIGIN(circ)) 137 continue; 138 ocirc = TO_ORIGIN_CIRCUIT(circ); 139 ocirc->n_written_circ_bw = ocirc->n_read_circ_bw = 0; 140 ocirc->n_overhead_written_circ_bw = ocirc->n_overhead_read_circ_bw = 0; 141 ocirc->n_delivered_written_circ_bw = ocirc->n_delivered_read_circ_bw = 0; 142 } 143 SMARTLIST_FOREACH_END(circ); 144 } 145 146 /* Helper to emit the BUILDTIMEOUT_SET circuit build time event */ 147 void 148 cbt_control_event_buildtimeout_set(const circuit_build_times_t *cbt, 149 buildtimeout_set_event_t type) 150 { 151 char *args = NULL; 152 double qnt; 153 double timeout_rate = 0.0; 154 double close_rate = 0.0; 155 156 switch (type) { 157 case BUILDTIMEOUT_SET_EVENT_RESET: 158 case BUILDTIMEOUT_SET_EVENT_SUSPENDED: 159 case BUILDTIMEOUT_SET_EVENT_DISCARD: 160 qnt = 1.0; 161 break; 162 case BUILDTIMEOUT_SET_EVENT_COMPUTED: 163 case BUILDTIMEOUT_SET_EVENT_RESUME: 164 default: 165 qnt = circuit_build_times_quantile_cutoff(); 166 break; 167 } 168 169 /* The timeout rate is the ratio of the timeout count over 170 * the total number of circuits attempted. The total number of 171 * circuits is (timeouts+succeeded), since every circuit 172 * either succeeds, or times out. "Closed" circuits are 173 * MEASURE_TIMEOUT circuits whose measurement period expired. 174 * All MEASURE_TIMEOUT circuits are counted in the timeouts stat 175 * before transitioning to MEASURE_TIMEOUT (in 176 * circuit_build_times_mark_circ_as_measurement_only()). 177 * MEASURE_TIMEOUT circuits that succeed are *not* counted as 178 * "succeeded". See circuit_build_times_handle_completed_hop(). 179 * 180 * We cast the denominator 181 * to promote it to double before the addition, to avoid int32 182 * overflow. */ 183 const double total_circuits = 184 ((double)cbt->num_circ_timeouts) + cbt->num_circ_succeeded; 185 if (total_circuits >= 1.0) { 186 timeout_rate = cbt->num_circ_timeouts / total_circuits; 187 close_rate = cbt->num_circ_closed / total_circuits; 188 } 189 190 tor_asprintf(&args, "TOTAL_TIMES=%lu " 191 "TIMEOUT_MS=%lu XM=%lu ALPHA=%f CUTOFF_QUANTILE=%f " 192 "TIMEOUT_RATE=%f CLOSE_MS=%lu CLOSE_RATE=%f", 193 (unsigned long)cbt->total_build_times, 194 (unsigned long)cbt->timeout_ms, 195 (unsigned long)cbt->Xm, cbt->alpha, qnt, 196 timeout_rate, 197 (unsigned long)cbt->close_ms, 198 close_rate); 199 200 control_event_buildtimeout_set(type, args); 201 202 tor_free(args); 203 } 204 /** Set <b>global_event_mask*</b> to the bitwise OR of each live control 205 * connection's event_mask field. */ 206 void 207 control_update_global_event_mask(void) 208 { 209 smartlist_t *conns = get_connection_array(); 210 event_mask_t old_mask, new_mask; 211 old_mask = global_event_mask; 212 int any_old_per_sec_events = control_any_per_second_event_enabled(); 213 214 global_event_mask = 0; 215 SMARTLIST_FOREACH(conns, connection_t *, _conn, 216 { 217 if (_conn->type == CONN_TYPE_CONTROL && 218 STATE_IS_OPEN(_conn->state)) { 219 control_connection_t *conn = TO_CONTROL_CONN(_conn); 220 global_event_mask |= conn->event_mask; 221 } 222 }); 223 224 new_mask = global_event_mask; 225 226 /* Handle the aftermath. Set up the log callback to tell us only what 227 * we want to hear...*/ 228 control_adjust_event_log_severity(); 229 230 /* Macro: true if ev was false before and is true now. */ 231 #define NEWLY_ENABLED(ev) \ 232 (! (old_mask & (ev)) && (new_mask & (ev))) 233 234 /* ...then, if we've started logging stream or circ bw, clear the 235 * appropriate fields. */ 236 if (NEWLY_ENABLED(EVENT_STREAM_BANDWIDTH_USED)) { 237 SMARTLIST_FOREACH(conns, connection_t *, conn, 238 { 239 if (conn->type == CONN_TYPE_AP) { 240 edge_connection_t *edge_conn = TO_EDGE_CONN(conn); 241 edge_conn->n_written = edge_conn->n_read = 0; 242 } 243 }); 244 } 245 if (NEWLY_ENABLED(EVENT_CIRC_BANDWIDTH_USED)) { 246 clear_circ_bw_fields(); 247 } 248 if (NEWLY_ENABLED(EVENT_BANDWIDTH_USED)) { 249 uint64_t r, w; 250 control_get_bytes_rw_last_sec(&r, &w); 251 } 252 if (any_old_per_sec_events != control_any_per_second_event_enabled()) { 253 rescan_periodic_events(get_options()); 254 } 255 256 #undef NEWLY_ENABLED 257 } 258 259 /** Given a control event code for a message event, return the corresponding 260 * log severity. */ 261 static inline int 262 event_to_log_severity(int event) 263 { 264 switch (event) { 265 case EVENT_DEBUG_MSG: return LOG_DEBUG; 266 case EVENT_INFO_MSG: return LOG_INFO; 267 case EVENT_NOTICE_MSG: return LOG_NOTICE; 268 case EVENT_WARN_MSG: return LOG_WARN; 269 case EVENT_ERR_MSG: return LOG_ERR; 270 default: return -1; 271 } 272 } 273 274 /** Adjust the log severities that result in control_event_logmsg being called 275 * to match the severity of log messages that any controllers are interested 276 * in. */ 277 void 278 control_adjust_event_log_severity(void) 279 { 280 int i; 281 int min_log_event=EVENT_ERR_MSG, max_log_event=EVENT_DEBUG_MSG; 282 283 for (i = EVENT_DEBUG_MSG; i <= EVENT_ERR_MSG; ++i) { 284 if (EVENT_IS_INTERESTING(i)) { 285 min_log_event = i; 286 break; 287 } 288 } 289 for (i = EVENT_ERR_MSG; i >= EVENT_DEBUG_MSG; --i) { 290 if (EVENT_IS_INTERESTING(i)) { 291 max_log_event = i; 292 break; 293 } 294 } 295 if (EVENT_IS_INTERESTING(EVENT_STATUS_GENERAL)) { 296 if (min_log_event > EVENT_NOTICE_MSG) 297 min_log_event = EVENT_NOTICE_MSG; 298 if (max_log_event < EVENT_ERR_MSG) 299 max_log_event = EVENT_ERR_MSG; 300 } 301 if (min_log_event <= max_log_event) 302 change_callback_log_severity(event_to_log_severity(min_log_event), 303 event_to_log_severity(max_log_event), 304 control_event_logmsg); 305 else 306 change_callback_log_severity(LOG_ERR, LOG_ERR, 307 control_event_logmsg); 308 } 309 310 /** Return true iff the event with code <b>c</b> is being sent to any current 311 * control connection. This is useful if the amount of work needed to prepare 312 * to call the appropriate control_event_...() function is high. 313 */ 314 int 315 control_event_is_interesting(int event) 316 { 317 return EVENT_IS_INTERESTING(event); 318 } 319 320 /** Return true if any event that needs to fire once a second is enabled. */ 321 int 322 control_any_per_second_event_enabled(void) 323 { 324 return ANY_EVENT_IS_INTERESTING( 325 EVENT_MASK_(EVENT_BANDWIDTH_USED) | 326 EVENT_MASK_(EVENT_CELL_STATS) | 327 EVENT_MASK_(EVENT_CIRC_BANDWIDTH_USED) | 328 EVENT_MASK_(EVENT_CONN_BW) | 329 EVENT_MASK_(EVENT_STREAM_BANDWIDTH_USED) 330 ); 331 } 332 333 /* The value of 'get_bytes_read()' the previous time that 334 * control_get_bytes_rw_last_sec() as called. */ 335 static uint64_t stats_prev_n_read = 0; 336 /* The value of 'get_bytes_written()' the previous time that 337 * control_get_bytes_rw_last_sec() as called. */ 338 static uint64_t stats_prev_n_written = 0; 339 340 /** 341 * Set <b>n_read</b> and <b>n_written</b> to the total number of bytes read 342 * and written by Tor since the last call to this function. 343 * 344 * Call this only from the main thread. 345 */ 346 static void 347 control_get_bytes_rw_last_sec(uint64_t *n_read, 348 uint64_t *n_written) 349 { 350 const uint64_t stats_n_bytes_read = get_bytes_read(); 351 const uint64_t stats_n_bytes_written = get_bytes_written(); 352 353 *n_read = stats_n_bytes_read - stats_prev_n_read; 354 *n_written = stats_n_bytes_written - stats_prev_n_written; 355 stats_prev_n_read = stats_n_bytes_read; 356 stats_prev_n_written = stats_n_bytes_written; 357 } 358 359 /** 360 * Run all the controller events (if any) that are scheduled to trigger once 361 * per second. 362 */ 363 void 364 control_per_second_events(void) 365 { 366 if (!control_any_per_second_event_enabled()) 367 return; 368 369 uint64_t bytes_read, bytes_written; 370 control_get_bytes_rw_last_sec(&bytes_read, &bytes_written); 371 control_event_bandwidth_used((uint32_t)bytes_read,(uint32_t)bytes_written); 372 373 control_event_stream_bandwidth_used(); 374 control_event_conn_bandwidth_used(); 375 control_event_circ_bandwidth_used(); 376 control_event_circuit_cell_stats(); 377 } 378 379 /** Represents an event that's queued to be sent to one or more 380 * controllers. */ 381 typedef struct queued_event_t { 382 uint16_t event; 383 char *msg; 384 } queued_event_t; 385 386 /** Pointer to int. If this is greater than 0, we don't allow new events to be 387 * queued. */ 388 static tor_threadlocal_t block_event_queue_flag; 389 390 /** Holds a smartlist of queued_event_t objects that may need to be sent 391 * to one or more controllers */ 392 static smartlist_t *queued_control_events = NULL; 393 394 /** True if the flush_queued_events_event is pending. */ 395 static int flush_queued_event_pending = 0; 396 397 /** Lock to protect the above fields. */ 398 static tor_mutex_t *queued_control_events_lock = NULL; 399 400 /** An event that should fire in order to flush the contents of 401 * queued_control_events. */ 402 static mainloop_event_t *flush_queued_events_event = NULL; 403 404 void 405 control_initialize_event_queue(void) 406 { 407 if (queued_control_events == NULL) { 408 queued_control_events = smartlist_new(); 409 } 410 411 if (flush_queued_events_event == NULL) { 412 struct event_base *b = tor_libevent_get_base(); 413 if (b) { 414 flush_queued_events_event = 415 mainloop_event_new(flush_queued_events_cb, NULL); 416 tor_assert(flush_queued_events_event); 417 } 418 } 419 420 if (queued_control_events_lock == NULL) { 421 queued_control_events_lock = tor_mutex_new(); 422 tor_threadlocal_init(&block_event_queue_flag); 423 } 424 } 425 426 static int * 427 get_block_event_queue(void) 428 { 429 int *val = tor_threadlocal_get(&block_event_queue_flag); 430 if (PREDICT_UNLIKELY(val == NULL)) { 431 val = tor_malloc_zero(sizeof(int)); 432 tor_threadlocal_set(&block_event_queue_flag, val); 433 } 434 return val; 435 } 436 437 /** Helper: inserts an event on the list of events queued to be sent to 438 * one or more controllers, and schedules the events to be flushed if needed. 439 * 440 * This function takes ownership of <b>msg</b>, and may free it. 441 * 442 * We queue these events rather than send them immediately in order to break 443 * the dependency in our callgraph from code that generates events for the 444 * controller, and the network layer at large. Otherwise, nearly every 445 * interesting part of Tor would potentially call every other interesting part 446 * of Tor. 447 */ 448 MOCK_IMPL(STATIC void, 449 queue_control_event_string,(uint16_t event, char *msg)) 450 { 451 /* This is redundant with checks done elsewhere, but it's a last-ditch 452 * attempt to avoid queueing something we shouldn't have to queue. */ 453 if (PREDICT_UNLIKELY( ! EVENT_IS_INTERESTING(event) )) { 454 tor_free(msg); 455 return; 456 } 457 458 int *block_event_queue = get_block_event_queue(); 459 if (*block_event_queue) { 460 tor_free(msg); 461 return; 462 } 463 464 queued_event_t *ev = tor_malloc(sizeof(*ev)); 465 ev->event = event; 466 ev->msg = msg; 467 468 /* No queueing an event while queueing an event */ 469 ++*block_event_queue; 470 471 tor_mutex_acquire(queued_control_events_lock); 472 tor_assert(queued_control_events); 473 smartlist_add(queued_control_events, ev); 474 475 int activate_event = 0; 476 if (! flush_queued_event_pending && in_main_thread()) { 477 activate_event = 1; 478 flush_queued_event_pending = 1; 479 } 480 481 tor_mutex_release(queued_control_events_lock); 482 483 --*block_event_queue; 484 485 /* We just put an event on the queue; mark the queue to be 486 * flushed. We only do this from the main thread for now; otherwise, 487 * we'd need to incur locking overhead in Libevent or use a socket. 488 */ 489 if (activate_event) { 490 tor_assert(flush_queued_events_event); 491 mainloop_event_activate(flush_queued_events_event); 492 } 493 } 494 495 #define queued_event_free(ev) \ 496 FREE_AND_NULL(queued_event_t, queued_event_free_, (ev)) 497 498 /** Release all storage held by <b>ev</b>. */ 499 static void 500 queued_event_free_(queued_event_t *ev) 501 { 502 if (ev == NULL) 503 return; 504 505 tor_free(ev->msg); 506 tor_free(ev); 507 } 508 509 /** Send every queued event to every controller that's interested in it, 510 * and remove the events from the queue. If <b>force</b> is true, 511 * then make all controllers send their data out immediately, since we 512 * may be about to shut down. */ 513 static void 514 queued_events_flush_all(int force) 515 { 516 /* Make sure that we get all the pending log events, if there are any. */ 517 flush_pending_log_callbacks(); 518 519 if (PREDICT_UNLIKELY(queued_control_events == NULL)) { 520 return; 521 } 522 smartlist_t *all_conns = get_connection_array(); 523 smartlist_t *controllers = smartlist_new(); 524 smartlist_t *queued_events; 525 526 int *block_event_queue = get_block_event_queue(); 527 ++*block_event_queue; 528 529 tor_mutex_acquire(queued_control_events_lock); 530 /* No queueing an event while flushing events. */ 531 flush_queued_event_pending = 0; 532 queued_events = queued_control_events; 533 queued_control_events = smartlist_new(); 534 tor_mutex_release(queued_control_events_lock); 535 536 /* Gather all the controllers that will care... */ 537 SMARTLIST_FOREACH_BEGIN(all_conns, connection_t *, conn) { 538 if (conn->type == CONN_TYPE_CONTROL && 539 !conn->marked_for_close && 540 conn->state == CONTROL_CONN_STATE_OPEN) { 541 control_connection_t *control_conn = TO_CONTROL_CONN(conn); 542 543 smartlist_add(controllers, control_conn); 544 } 545 } SMARTLIST_FOREACH_END(conn); 546 547 SMARTLIST_FOREACH_BEGIN(queued_events, queued_event_t *, ev) { 548 const event_mask_t bit = ((event_mask_t)1) << ev->event; 549 const size_t msg_len = strlen(ev->msg); 550 SMARTLIST_FOREACH_BEGIN(controllers, control_connection_t *, 551 control_conn) { 552 if (control_conn->event_mask & bit) { 553 connection_buf_add(ev->msg, msg_len, TO_CONN(control_conn)); 554 } 555 } SMARTLIST_FOREACH_END(control_conn); 556 557 queued_event_free(ev); 558 } SMARTLIST_FOREACH_END(ev); 559 560 if (force) { 561 SMARTLIST_FOREACH_BEGIN(controllers, control_connection_t *, 562 control_conn) { 563 connection_flush(TO_CONN(control_conn)); 564 } SMARTLIST_FOREACH_END(control_conn); 565 } 566 567 smartlist_free(queued_events); 568 smartlist_free(controllers); 569 570 --*block_event_queue; 571 } 572 573 /** Libevent callback: Flushes pending events to controllers that are 574 * interested in them. */ 575 static void 576 flush_queued_events_cb(mainloop_event_t *event, void *arg) 577 { 578 (void) event; 579 (void) arg; 580 queued_events_flush_all(0); 581 } 582 583 /** Send an event to all v1 controllers that are listening for code 584 * <b>event</b>. The event's body is given by <b>msg</b>. 585 * 586 * The EXTENDED_FORMAT and NONEXTENDED_FORMAT flags behave similarly with 587 * respect to the EXTENDED_EVENTS feature. */ 588 MOCK_IMPL(STATIC void, 589 send_control_event_string,(uint16_t event, 590 const char *msg)) 591 { 592 tor_assert(event >= EVENT_MIN_ && event <= EVENT_MAX_); 593 queue_control_event_string(event, tor_strdup(msg)); 594 } 595 596 /** Helper for send_control_event and control_event_status: 597 * Send an event to all v1 controllers that are listening for code 598 * <b>event</b>. The event's body is created by the printf-style format in 599 * <b>format</b>, and other arguments as provided. */ 600 static void 601 send_control_event_impl(uint16_t event, 602 const char *format, va_list ap) 603 { 604 char *buf = NULL; 605 int len; 606 607 len = tor_vasprintf(&buf, format, ap); 608 if (len < 0) { 609 log_warn(LD_BUG, "Unable to format event for controller."); 610 return; 611 } 612 613 queue_control_event_string(event, buf); 614 } 615 616 /** Send an event to all v1 controllers that are listening for code 617 * <b>event</b>. The event's body is created by the printf-style format in 618 * <b>format</b>, and other arguments as provided. */ 619 static void 620 send_control_event(uint16_t event, 621 const char *format, ...) 622 { 623 va_list ap; 624 va_start(ap, format); 625 send_control_event_impl(event, format, ap); 626 va_end(ap); 627 } 628 629 /** Something major has happened to circuit <b>circ</b>: tell any 630 * interested control connections. */ 631 int 632 control_event_circuit_status(origin_circuit_t *circ, circuit_status_event_t tp, 633 int reason_code) 634 { 635 const char *status; 636 char reasons[64] = ""; 637 638 if (!EVENT_IS_INTERESTING(EVENT_CIRCUIT_STATUS)) 639 return 0; 640 tor_assert(circ); 641 642 switch (tp) 643 { 644 case CIRC_EVENT_LAUNCHED: status = "LAUNCHED"; break; 645 case CIRC_EVENT_BUILT: status = "BUILT"; break; 646 case CIRC_EVENT_EXTENDED: status = "EXTENDED"; break; 647 case CIRC_EVENT_FAILED: status = "FAILED"; break; 648 case CIRC_EVENT_CLOSED: status = "CLOSED"; break; 649 default: 650 log_warn(LD_BUG, "Unrecognized status code %d", (int)tp); 651 tor_fragile_assert(); 652 return 0; 653 } 654 655 if (tp == CIRC_EVENT_FAILED || tp == CIRC_EVENT_CLOSED) { 656 const char *reason_str = circuit_end_reason_to_control_string(reason_code); 657 char unk_reason_buf[16]; 658 if (!reason_str) { 659 tor_snprintf(unk_reason_buf, 16, "UNKNOWN_%d", reason_code); 660 reason_str = unk_reason_buf; 661 } 662 if (reason_code > 0 && reason_code & END_CIRC_REASON_FLAG_REMOTE) { 663 tor_snprintf(reasons, sizeof(reasons), 664 " REASON=DESTROYED REMOTE_REASON=%s", reason_str); 665 } else { 666 tor_snprintf(reasons, sizeof(reasons), 667 " REASON=%s", reason_str); 668 } 669 } 670 671 { 672 char *circdesc = circuit_describe_status_for_controller(circ); 673 const char *sp = strlen(circdesc) ? " " : ""; 674 send_control_event(EVENT_CIRCUIT_STATUS, 675 "650 CIRC %lu %s%s%s%s\r\n", 676 (unsigned long)circ->global_identifier, 677 status, sp, 678 circdesc, 679 reasons); 680 tor_free(circdesc); 681 } 682 683 return 0; 684 } 685 686 /** Something minor has happened to circuit <b>circ</b>: tell any 687 * interested control connections. */ 688 static int 689 control_event_circuit_status_minor(origin_circuit_t *circ, 690 circuit_status_minor_event_t e, 691 int purpose, const struct timeval *tv) 692 { 693 const char *event_desc; 694 char event_tail[160] = ""; 695 if (!EVENT_IS_INTERESTING(EVENT_CIRCUIT_STATUS_MINOR)) 696 return 0; 697 tor_assert(circ); 698 699 switch (e) 700 { 701 case CIRC_MINOR_EVENT_PURPOSE_CHANGED: 702 event_desc = "PURPOSE_CHANGED"; 703 704 { 705 /* event_tail can currently be up to 68 chars long */ 706 const char *hs_state_str = 707 circuit_purpose_to_controller_hs_state_string(purpose); 708 tor_snprintf(event_tail, sizeof(event_tail), 709 " OLD_PURPOSE=%s%s%s", 710 circuit_purpose_to_controller_string(purpose), 711 (hs_state_str != NULL) ? " OLD_HS_STATE=" : "", 712 (hs_state_str != NULL) ? hs_state_str : ""); 713 } 714 715 break; 716 case CIRC_MINOR_EVENT_CANNIBALIZED: 717 event_desc = "CANNIBALIZED"; 718 719 { 720 /* event_tail can currently be up to 130 chars long */ 721 const char *hs_state_str = 722 circuit_purpose_to_controller_hs_state_string(purpose); 723 const struct timeval *old_timestamp_began = tv; 724 char tbuf[ISO_TIME_USEC_LEN+1]; 725 format_iso_time_nospace_usec(tbuf, old_timestamp_began); 726 727 tor_snprintf(event_tail, sizeof(event_tail), 728 " OLD_PURPOSE=%s%s%s OLD_TIME_CREATED=%s", 729 circuit_purpose_to_controller_string(purpose), 730 (hs_state_str != NULL) ? " OLD_HS_STATE=" : "", 731 (hs_state_str != NULL) ? hs_state_str : "", 732 tbuf); 733 } 734 735 break; 736 default: 737 log_warn(LD_BUG, "Unrecognized status code %d", (int)e); 738 tor_fragile_assert(); 739 return 0; 740 } 741 742 { 743 char *circdesc = circuit_describe_status_for_controller(circ); 744 const char *sp = strlen(circdesc) ? " " : ""; 745 send_control_event(EVENT_CIRCUIT_STATUS_MINOR, 746 "650 CIRC_MINOR %lu %s%s%s%s\r\n", 747 (unsigned long)circ->global_identifier, 748 event_desc, sp, 749 circdesc, 750 event_tail); 751 tor_free(circdesc); 752 } 753 754 return 0; 755 } 756 757 /** 758 * <b>circ</b> has changed its purpose from <b>old_purpose</b>: tell any 759 * interested controllers. 760 */ 761 int 762 control_event_circuit_purpose_changed(origin_circuit_t *circ, 763 int old_purpose) 764 { 765 return control_event_circuit_status_minor(circ, 766 CIRC_MINOR_EVENT_PURPOSE_CHANGED, 767 old_purpose, 768 NULL); 769 } 770 771 /** 772 * <b>circ</b> has changed its purpose from <b>old_purpose</b>, and its 773 * created-time from <b>old_tv_created</b>: tell any interested controllers. 774 */ 775 int 776 control_event_circuit_cannibalized(origin_circuit_t *circ, 777 int old_purpose, 778 const struct timeval *old_tv_created) 779 { 780 return control_event_circuit_status_minor(circ, 781 CIRC_MINOR_EVENT_CANNIBALIZED, 782 old_purpose, 783 old_tv_created); 784 } 785 786 /** Something has happened to the stream associated with AP connection 787 * <b>conn</b>: tell any interested control connections. */ 788 int 789 control_event_stream_status(entry_connection_t *conn, stream_status_event_t tp, 790 int reason_code) 791 { 792 char reason_buf[64]; 793 char addrport_buf[64]; 794 const char *status; 795 circuit_t *circ; 796 origin_circuit_t *origin_circ = NULL; 797 char buf[256]; 798 const char *purpose = ""; 799 tor_assert(conn->socks_request); 800 801 if (!EVENT_IS_INTERESTING(EVENT_STREAM_STATUS)) 802 return 0; 803 804 if (tp == STREAM_EVENT_CLOSED && 805 (reason_code & END_STREAM_REASON_FLAG_ALREADY_SENT_CLOSED)) 806 return 0; 807 808 write_stream_target_to_buf(conn, buf, sizeof(buf)); 809 810 reason_buf[0] = '\0'; 811 switch (tp) 812 { 813 case STREAM_EVENT_SENT_CONNECT: status = "SENTCONNECT"; break; 814 case STREAM_EVENT_SENT_RESOLVE: status = "SENTRESOLVE"; break; 815 case STREAM_EVENT_SUCCEEDED: status = "SUCCEEDED"; break; 816 case STREAM_EVENT_FAILED: status = "FAILED"; break; 817 case STREAM_EVENT_CLOSED: status = "CLOSED"; break; 818 case STREAM_EVENT_NEW: status = "NEW"; break; 819 case STREAM_EVENT_NEW_RESOLVE: status = "NEWRESOLVE"; break; 820 case STREAM_EVENT_FAILED_RETRIABLE: status = "DETACHED"; break; 821 case STREAM_EVENT_REMAP: status = "REMAP"; break; 822 case STREAM_EVENT_CONTROLLER_WAIT: status = "CONTROLLER_WAIT"; break; 823 case STREAM_EVENT_XOFF_SENT: status = "XOFF_SENT"; break; 824 case STREAM_EVENT_XOFF_RECV: status = "XOFF_RECV"; break; 825 case STREAM_EVENT_XON_SENT: status = "XON_SENT"; break; 826 case STREAM_EVENT_XON_RECV: status = "XON_RECV"; break; 827 default: 828 log_warn(LD_BUG, "Unrecognized status code %d", (int)tp); 829 return 0; 830 } 831 if (reason_code && (tp == STREAM_EVENT_FAILED || 832 tp == STREAM_EVENT_CLOSED || 833 tp == STREAM_EVENT_FAILED_RETRIABLE)) { 834 const char *reason_str = stream_end_reason_to_control_string(reason_code); 835 char *r = NULL; 836 if (!reason_str) { 837 tor_asprintf(&r, " UNKNOWN_%d", reason_code); 838 reason_str = r; 839 } 840 if (reason_code & END_STREAM_REASON_FLAG_REMOTE) 841 tor_snprintf(reason_buf, sizeof(reason_buf), 842 " REASON=END REMOTE_REASON=%s", reason_str); 843 else 844 tor_snprintf(reason_buf, sizeof(reason_buf), 845 " REASON=%s", reason_str); 846 tor_free(r); 847 } else if (reason_code && tp == STREAM_EVENT_REMAP) { 848 switch (reason_code) { 849 case REMAP_STREAM_SOURCE_CACHE: 850 strlcpy(reason_buf, " SOURCE=CACHE", sizeof(reason_buf)); 851 break; 852 case REMAP_STREAM_SOURCE_EXIT: 853 strlcpy(reason_buf, " SOURCE=EXIT", sizeof(reason_buf)); 854 break; 855 default: 856 tor_snprintf(reason_buf, sizeof(reason_buf), " REASON=UNKNOWN_%d", 857 reason_code); 858 /* XXX do we want SOURCE=UNKNOWN_%d above instead? -RD */ 859 break; 860 } 861 } 862 863 if (tp == STREAM_EVENT_NEW || tp == STREAM_EVENT_NEW_RESOLVE) { 864 /* 865 * When the control conn is an AF_UNIX socket and we have no address, 866 * it gets set to "(Tor_internal)"; see dnsserv_launch_request() in 867 * dnsserv.c. 868 */ 869 if (strcmp(ENTRY_TO_CONN(conn)->address, "(Tor_internal)") != 0) { 870 tor_snprintf(addrport_buf,sizeof(addrport_buf), " SOURCE_ADDR=%s:%d", 871 ENTRY_TO_CONN(conn)->address, ENTRY_TO_CONN(conn)->port); 872 } else { 873 /* 874 * else leave it blank so control on AF_UNIX doesn't need to make 875 * something up. 876 */ 877 addrport_buf[0] = '\0'; 878 } 879 } else { 880 addrport_buf[0] = '\0'; 881 } 882 883 if (tp == STREAM_EVENT_NEW_RESOLVE) { 884 purpose = " PURPOSE=DNS_REQUEST"; 885 } else if (tp == STREAM_EVENT_NEW) { 886 if (conn->use_begindir) { 887 connection_t *linked = ENTRY_TO_CONN(conn)->linked_conn; 888 int linked_dir_purpose = -1; 889 if (linked && linked->type == CONN_TYPE_DIR) 890 linked_dir_purpose = linked->purpose; 891 if (DIR_PURPOSE_IS_UPLOAD(linked_dir_purpose)) 892 purpose = " PURPOSE=DIR_UPLOAD"; 893 else 894 purpose = " PURPOSE=DIR_FETCH"; 895 } else 896 purpose = " PURPOSE=USER"; 897 } 898 899 circ = circuit_get_by_edge_conn(ENTRY_TO_EDGE_CONN(conn)); 900 if (circ && CIRCUIT_IS_ORIGIN(circ)) 901 origin_circ = TO_ORIGIN_CIRCUIT(circ); 902 903 { 904 char *conndesc = entry_connection_describe_status_for_controller(conn); 905 const char *sp = strlen(conndesc) ? " " : ""; 906 send_control_event(EVENT_STREAM_STATUS, 907 "650 STREAM %"PRIu64" %s %lu %s%s%s%s%s%s\r\n", 908 (ENTRY_TO_CONN(conn)->global_identifier), 909 status, 910 origin_circ? 911 (unsigned long)origin_circ->global_identifier : 0ul, 912 buf, reason_buf, addrport_buf, purpose, sp, conndesc); 913 tor_free(conndesc); 914 } 915 916 /* XXX need to specify its intended exit, etc? */ 917 918 return 0; 919 } 920 921 /** Called when the status of an OR connection <b>conn</b> changes: tell any 922 * interested control connections. <b>tp</b> is the new status for the 923 * connection. If <b>conn</b> has just closed or failed, then <b>reason</b> 924 * may be the reason why. 925 */ 926 int 927 control_event_or_conn_status(or_connection_t *conn, or_conn_status_event_t tp, 928 int reason) 929 { 930 int ncircs = 0; 931 const char *status; 932 char name[128]; 933 char ncircs_buf[32] = {0}; /* > 8 + log10(2^32)=10 + 2 */ 934 935 if (!EVENT_IS_INTERESTING(EVENT_OR_CONN_STATUS)) 936 return 0; 937 938 switch (tp) 939 { 940 case OR_CONN_EVENT_LAUNCHED: status = "LAUNCHED"; break; 941 case OR_CONN_EVENT_CONNECTED: status = "CONNECTED"; break; 942 case OR_CONN_EVENT_FAILED: status = "FAILED"; break; 943 case OR_CONN_EVENT_CLOSED: status = "CLOSED"; break; 944 case OR_CONN_EVENT_NEW: status = "NEW"; break; 945 default: 946 log_warn(LD_BUG, "Unrecognized status code %d", (int)tp); 947 return 0; 948 } 949 if (conn->chan) { 950 ncircs = circuit_count_pending_on_channel(TLS_CHAN_TO_BASE(conn->chan)); 951 } else { 952 ncircs = 0; 953 } 954 ncircs += connection_or_get_num_circuits(conn); 955 if (ncircs && (tp == OR_CONN_EVENT_FAILED || tp == OR_CONN_EVENT_CLOSED)) { 956 tor_snprintf(ncircs_buf, sizeof(ncircs_buf), " NCIRCS=%d", ncircs); 957 } 958 959 orconn_target_get_name(name, sizeof(name), conn); 960 send_control_event(EVENT_OR_CONN_STATUS, 961 "650 ORCONN %s %s%s%s%s ID=%"PRIu64"\r\n", 962 name, status, 963 reason ? " REASON=" : "", 964 orconn_end_reason_to_control_string(reason), 965 ncircs_buf, 966 (conn->base_.global_identifier)); 967 968 return 0; 969 } 970 971 /** 972 * Print out STREAM_BW event for a single conn 973 */ 974 int 975 control_event_stream_bandwidth(edge_connection_t *edge_conn) 976 { 977 struct timeval now; 978 char tbuf[ISO_TIME_USEC_LEN+1]; 979 if (EVENT_IS_INTERESTING(EVENT_STREAM_BANDWIDTH_USED)) { 980 if (!edge_conn->n_read && !edge_conn->n_written) 981 return 0; 982 983 tor_gettimeofday(&now); 984 format_iso_time_nospace_usec(tbuf, &now); 985 send_control_event(EVENT_STREAM_BANDWIDTH_USED, 986 "650 STREAM_BW %"PRIu64" %lu %lu %s\r\n", 987 (edge_conn->base_.global_identifier), 988 (unsigned long)edge_conn->n_read, 989 (unsigned long)edge_conn->n_written, 990 tbuf); 991 992 edge_conn->n_written = edge_conn->n_read = 0; 993 } 994 995 return 0; 996 } 997 998 /** A second or more has elapsed: tell any interested control 999 * connections how much bandwidth streams have used. */ 1000 int 1001 control_event_stream_bandwidth_used(void) 1002 { 1003 if (EVENT_IS_INTERESTING(EVENT_STREAM_BANDWIDTH_USED)) { 1004 smartlist_t *conns = get_connection_array(); 1005 edge_connection_t *edge_conn; 1006 struct timeval now; 1007 char tbuf[ISO_TIME_USEC_LEN+1]; 1008 1009 SMARTLIST_FOREACH_BEGIN(conns, connection_t *, conn) 1010 { 1011 if (conn->type != CONN_TYPE_AP) 1012 continue; 1013 edge_conn = TO_EDGE_CONN(conn); 1014 if (!edge_conn->n_read && !edge_conn->n_written) 1015 continue; 1016 1017 tor_gettimeofday(&now); 1018 format_iso_time_nospace_usec(tbuf, &now); 1019 send_control_event(EVENT_STREAM_BANDWIDTH_USED, 1020 "650 STREAM_BW %"PRIu64" %lu %lu %s\r\n", 1021 (edge_conn->base_.global_identifier), 1022 (unsigned long)edge_conn->n_read, 1023 (unsigned long)edge_conn->n_written, 1024 tbuf); 1025 1026 edge_conn->n_written = edge_conn->n_read = 0; 1027 } 1028 SMARTLIST_FOREACH_END(conn); 1029 } 1030 1031 return 0; 1032 } 1033 1034 /** A second or more has elapsed: tell any interested control connections 1035 * how much bandwidth origin circuits have used. */ 1036 int 1037 control_event_circ_bandwidth_used(void) 1038 { 1039 if (!EVENT_IS_INTERESTING(EVENT_CIRC_BANDWIDTH_USED)) 1040 return 0; 1041 1042 SMARTLIST_FOREACH_BEGIN(circuit_get_global_list(), circuit_t *, circ) { 1043 if (!CIRCUIT_IS_ORIGIN(circ)) 1044 continue; 1045 1046 control_event_circ_bandwidth_used_for_circ(TO_ORIGIN_CIRCUIT(circ)); 1047 } 1048 SMARTLIST_FOREACH_END(circ); 1049 1050 return 0; 1051 } 1052 1053 /** 1054 * Emit a CIRC_BW event line for a specific circuit. 1055 * 1056 * This function sets the values it emits to 0, and does not emit 1057 * an event if there is no new data to report since the last call. 1058 * 1059 * Therefore, it may be called at any frequency. 1060 */ 1061 int 1062 control_event_circ_bandwidth_used_for_circ(origin_circuit_t *ocirc) 1063 { 1064 struct timeval now; 1065 char tbuf[ISO_TIME_USEC_LEN+1]; 1066 1067 tor_assert(ocirc); 1068 1069 if (!EVENT_IS_INTERESTING(EVENT_CIRC_BANDWIDTH_USED)) 1070 return 0; 1071 1072 /* n_read_circ_bw and n_written_circ_bw are always updated 1073 * when there is any new cell on a circuit, and set to 0 after 1074 * the event, below. 1075 * 1076 * Therefore, checking them is sufficient to determine if there 1077 * is new data to report. */ 1078 if (!ocirc->n_read_circ_bw && !ocirc->n_written_circ_bw) 1079 return 0; 1080 1081 tor_gettimeofday(&now); 1082 format_iso_time_nospace_usec(tbuf, &now); 1083 1084 char *ccontrol_buf = congestion_control_get_control_port_fields(ocirc); 1085 send_control_event(EVENT_CIRC_BANDWIDTH_USED, 1086 "650 CIRC_BW ID=%d READ=%lu WRITTEN=%lu TIME=%s " 1087 "DELIVERED_READ=%lu OVERHEAD_READ=%lu " 1088 "DELIVERED_WRITTEN=%lu OVERHEAD_WRITTEN=%lu%s\r\n", 1089 ocirc->global_identifier, 1090 (unsigned long)ocirc->n_read_circ_bw, 1091 (unsigned long)ocirc->n_written_circ_bw, 1092 tbuf, 1093 (unsigned long)ocirc->n_delivered_read_circ_bw, 1094 (unsigned long)ocirc->n_overhead_read_circ_bw, 1095 (unsigned long)ocirc->n_delivered_written_circ_bw, 1096 (unsigned long)ocirc->n_overhead_written_circ_bw, 1097 ccontrol_buf ? ccontrol_buf : ""); 1098 1099 ocirc->n_written_circ_bw = ocirc->n_read_circ_bw = 0; 1100 ocirc->n_overhead_written_circ_bw = ocirc->n_overhead_read_circ_bw = 0; 1101 ocirc->n_delivered_written_circ_bw = ocirc->n_delivered_read_circ_bw = 0; 1102 1103 if (ccontrol_buf) 1104 tor_free(ccontrol_buf); 1105 1106 return 0; 1107 } 1108 1109 /** Print out CONN_BW event for a single OR/DIR/EXIT <b>conn</b> and reset 1110 * bandwidth counters. */ 1111 int 1112 control_event_conn_bandwidth(connection_t *conn) 1113 { 1114 const char *conn_type_str; 1115 if (!get_options()->TestingEnableConnBwEvent || 1116 !EVENT_IS_INTERESTING(EVENT_CONN_BW)) 1117 return 0; 1118 if (!conn->n_read_conn_bw && !conn->n_written_conn_bw) 1119 return 0; 1120 switch (conn->type) { 1121 case CONN_TYPE_OR: 1122 conn_type_str = "OR"; 1123 break; 1124 case CONN_TYPE_DIR: 1125 conn_type_str = "DIR"; 1126 break; 1127 case CONN_TYPE_EXIT: 1128 conn_type_str = "EXIT"; 1129 break; 1130 default: 1131 return 0; 1132 } 1133 send_control_event(EVENT_CONN_BW, 1134 "650 CONN_BW ID=%"PRIu64" TYPE=%s " 1135 "READ=%lu WRITTEN=%lu\r\n", 1136 (conn->global_identifier), 1137 conn_type_str, 1138 (unsigned long)conn->n_read_conn_bw, 1139 (unsigned long)conn->n_written_conn_bw); 1140 conn->n_written_conn_bw = conn->n_read_conn_bw = 0; 1141 return 0; 1142 } 1143 1144 /** A second or more has elapsed: tell any interested control 1145 * connections how much bandwidth connections have used. */ 1146 int 1147 control_event_conn_bandwidth_used(void) 1148 { 1149 if (get_options()->TestingEnableConnBwEvent && 1150 EVENT_IS_INTERESTING(EVENT_CONN_BW)) { 1151 SMARTLIST_FOREACH(get_connection_array(), connection_t *, conn, 1152 control_event_conn_bandwidth(conn)); 1153 } 1154 return 0; 1155 } 1156 1157 /** Helper: iterate over cell statistics of <b>circ</b> and sum up added 1158 * cells, removed cells, and waiting times by cell command and direction. 1159 * Store results in <b>cell_stats</b>. Free cell statistics of the 1160 * circuit afterwards. */ 1161 void 1162 sum_up_cell_stats_by_command(circuit_t *circ, cell_stats_t *cell_stats) 1163 { 1164 memset(cell_stats, 0, sizeof(cell_stats_t)); 1165 SMARTLIST_FOREACH_BEGIN(circ->testing_cell_stats, 1166 const testing_cell_stats_entry_t *, ent) { 1167 tor_assert(ent->command <= CELL_COMMAND_MAX_); 1168 if (!ent->removed && !ent->exitward) { 1169 cell_stats->added_cells_appward[ent->command] += 1; 1170 } else if (!ent->removed && ent->exitward) { 1171 cell_stats->added_cells_exitward[ent->command] += 1; 1172 } else if (!ent->exitward) { 1173 cell_stats->removed_cells_appward[ent->command] += 1; 1174 cell_stats->total_time_appward[ent->command] += ent->waiting_time * 10; 1175 } else { 1176 cell_stats->removed_cells_exitward[ent->command] += 1; 1177 cell_stats->total_time_exitward[ent->command] += ent->waiting_time * 10; 1178 } 1179 } SMARTLIST_FOREACH_END(ent); 1180 circuit_clear_testing_cell_stats(circ); 1181 } 1182 1183 /** Helper: append a cell statistics string to <code>event_parts</code>, 1184 * prefixed with <code>key</code>=. Statistics consist of comma-separated 1185 * key:value pairs with lower-case command strings as keys and cell 1186 * numbers or total waiting times as values. A key:value pair is included 1187 * if the entry in <code>include_if_non_zero</code> is not zero, but with 1188 * the (possibly zero) entry from <code>number_to_include</code>. Both 1189 * arrays are expected to have a length of CELL_COMMAND_MAX_ + 1. If no 1190 * entry in <code>include_if_non_zero</code> is positive, no string will 1191 * be added to <code>event_parts</code>. */ 1192 void 1193 append_cell_stats_by_command(smartlist_t *event_parts, const char *key, 1194 const uint64_t *include_if_non_zero, 1195 const uint64_t *number_to_include) 1196 { 1197 smartlist_t *key_value_strings = smartlist_new(); 1198 int i; 1199 for (i = 0; i <= CELL_COMMAND_MAX_; i++) { 1200 if (include_if_non_zero[i] > 0) { 1201 smartlist_add_asprintf(key_value_strings, "%s:%"PRIu64, 1202 cell_command_to_string(i), 1203 (number_to_include[i])); 1204 } 1205 } 1206 if (smartlist_len(key_value_strings) > 0) { 1207 char *joined = smartlist_join_strings(key_value_strings, ",", 0, NULL); 1208 smartlist_add_asprintf(event_parts, "%s=%s", key, joined); 1209 SMARTLIST_FOREACH(key_value_strings, char *, cp, tor_free(cp)); 1210 tor_free(joined); 1211 } 1212 smartlist_free(key_value_strings); 1213 } 1214 1215 /** Helper: format <b>cell_stats</b> for <b>circ</b> for inclusion in a 1216 * CELL_STATS event and write result string to <b>event_string</b>. */ 1217 void 1218 format_cell_stats(char **event_string, circuit_t *circ, 1219 cell_stats_t *cell_stats) 1220 { 1221 smartlist_t *event_parts = smartlist_new(); 1222 if (CIRCUIT_IS_ORIGIN(circ)) { 1223 origin_circuit_t *ocirc = TO_ORIGIN_CIRCUIT(circ); 1224 smartlist_add_asprintf(event_parts, "ID=%lu", 1225 (unsigned long)ocirc->global_identifier); 1226 } else if (TO_OR_CIRCUIT(circ)->p_chan) { 1227 or_circuit_t *or_circ = TO_OR_CIRCUIT(circ); 1228 smartlist_add_asprintf(event_parts, "InboundQueue=%lu", 1229 (unsigned long)or_circ->p_circ_id); 1230 smartlist_add_asprintf(event_parts, "InboundConn=%"PRIu64, 1231 (or_circ->p_chan->global_identifier)); 1232 append_cell_stats_by_command(event_parts, "InboundAdded", 1233 cell_stats->added_cells_appward, 1234 cell_stats->added_cells_appward); 1235 append_cell_stats_by_command(event_parts, "InboundRemoved", 1236 cell_stats->removed_cells_appward, 1237 cell_stats->removed_cells_appward); 1238 append_cell_stats_by_command(event_parts, "InboundTime", 1239 cell_stats->removed_cells_appward, 1240 cell_stats->total_time_appward); 1241 } 1242 if (circ->n_chan) { 1243 smartlist_add_asprintf(event_parts, "OutboundQueue=%lu", 1244 (unsigned long)circ->n_circ_id); 1245 smartlist_add_asprintf(event_parts, "OutboundConn=%"PRIu64, 1246 (circ->n_chan->global_identifier)); 1247 append_cell_stats_by_command(event_parts, "OutboundAdded", 1248 cell_stats->added_cells_exitward, 1249 cell_stats->added_cells_exitward); 1250 append_cell_stats_by_command(event_parts, "OutboundRemoved", 1251 cell_stats->removed_cells_exitward, 1252 cell_stats->removed_cells_exitward); 1253 append_cell_stats_by_command(event_parts, "OutboundTime", 1254 cell_stats->removed_cells_exitward, 1255 cell_stats->total_time_exitward); 1256 } 1257 *event_string = smartlist_join_strings(event_parts, " ", 0, NULL); 1258 SMARTLIST_FOREACH(event_parts, char *, cp, tor_free(cp)); 1259 smartlist_free(event_parts); 1260 } 1261 1262 /** A second or more has elapsed: tell any interested control connection 1263 * how many cells have been processed for a given circuit. */ 1264 int 1265 control_event_circuit_cell_stats(void) 1266 { 1267 cell_stats_t *cell_stats; 1268 char *event_string; 1269 if (!get_options()->TestingEnableCellStatsEvent || 1270 !EVENT_IS_INTERESTING(EVENT_CELL_STATS)) 1271 return 0; 1272 cell_stats = tor_malloc(sizeof(cell_stats_t)); 1273 SMARTLIST_FOREACH_BEGIN(circuit_get_global_list(), circuit_t *, circ) { 1274 if (!circ->testing_cell_stats) 1275 continue; 1276 sum_up_cell_stats_by_command(circ, cell_stats); 1277 format_cell_stats(&event_string, circ, cell_stats); 1278 send_control_event(EVENT_CELL_STATS, 1279 "650 CELL_STATS %s\r\n", event_string); 1280 tor_free(event_string); 1281 } 1282 SMARTLIST_FOREACH_END(circ); 1283 tor_free(cell_stats); 1284 return 0; 1285 } 1286 1287 /* about 5 minutes worth. */ 1288 #define N_BW_EVENTS_TO_CACHE 300 1289 /* Index into cached_bw_events to next write. */ 1290 static int next_measurement_idx = 0; 1291 /* number of entries set in n_measurements */ 1292 static int n_measurements = 0; 1293 static struct cached_bw_event_t { 1294 uint32_t n_read; 1295 uint32_t n_written; 1296 } cached_bw_events[N_BW_EVENTS_TO_CACHE]; 1297 1298 void 1299 stats_init(void) 1300 { 1301 stats_prev_n_read = get_bytes_read(); 1302 stats_prev_n_written = get_bytes_written(); 1303 } 1304 1305 void 1306 stats_clear(void) 1307 { 1308 memset(cached_bw_events, 0, sizeof cached_bw_events); 1309 stats_prev_n_read = stats_prev_n_written = 0; 1310 n_measurements = next_measurement_idx = 0; 1311 } 1312 1313 /** A second or more has elapsed: tell any interested control 1314 * connections how much bandwidth we used. */ 1315 int 1316 control_event_bandwidth_used(uint32_t n_read, uint32_t n_written) 1317 { 1318 cached_bw_events[next_measurement_idx].n_read = n_read; 1319 cached_bw_events[next_measurement_idx].n_written = n_written; 1320 if (++next_measurement_idx == N_BW_EVENTS_TO_CACHE) 1321 next_measurement_idx = 0; 1322 if (n_measurements < N_BW_EVENTS_TO_CACHE) 1323 ++n_measurements; 1324 1325 if (EVENT_IS_INTERESTING(EVENT_BANDWIDTH_USED)) { 1326 send_control_event(EVENT_BANDWIDTH_USED, 1327 "650 BW %lu %lu\r\n", 1328 (unsigned long)n_read, 1329 (unsigned long)n_written); 1330 } 1331 1332 return 0; 1333 } 1334 1335 char * 1336 get_bw_samples(void) 1337 { 1338 int i; 1339 int idx = (next_measurement_idx + N_BW_EVENTS_TO_CACHE - n_measurements) 1340 % N_BW_EVENTS_TO_CACHE; 1341 tor_assert(0 <= idx && idx < N_BW_EVENTS_TO_CACHE); 1342 1343 smartlist_t *elements = smartlist_new(); 1344 1345 for (i = 0; i < n_measurements; ++i) { 1346 tor_assert(0 <= idx && idx < N_BW_EVENTS_TO_CACHE); 1347 const struct cached_bw_event_t *bwe = &cached_bw_events[idx]; 1348 1349 smartlist_add_asprintf(elements, "%u,%u", 1350 (unsigned)bwe->n_read, 1351 (unsigned)bwe->n_written); 1352 1353 idx = (idx + 1) % N_BW_EVENTS_TO_CACHE; 1354 } 1355 1356 char *result = smartlist_join_strings(elements, " ", 0, NULL); 1357 1358 SMARTLIST_FOREACH(elements, char *, cp, tor_free(cp)); 1359 smartlist_free(elements); 1360 1361 return result; 1362 } 1363 1364 /** Called when we are sending a log message to the controllers: suspend 1365 * sending further log messages to the controllers until we're done. Used by 1366 * CONN_LOG_PROTECT. */ 1367 void 1368 disable_control_logging(void) 1369 { 1370 ++disable_log_messages; 1371 } 1372 1373 /** We're done sending a log message to the controllers: re-enable controller 1374 * logging. Used by CONN_LOG_PROTECT. */ 1375 void 1376 enable_control_logging(void) 1377 { 1378 if (--disable_log_messages < 0) 1379 tor_assert(0); 1380 } 1381 1382 /** Remove newline and carriage-return characters from @a msg, replacing them 1383 * with spaces, and discarding any that appear at the end of the message */ 1384 void 1385 control_logmsg_strip_newlines(char *msg) 1386 { 1387 char *cp; 1388 for (cp = msg; *cp; ++cp) { 1389 if (*cp == '\r' || *cp == '\n') { 1390 *cp = ' '; 1391 } 1392 } 1393 if (cp == msg) 1394 return; 1395 /* Remove trailing spaces */ 1396 for (--cp; *cp == ' '; --cp) { 1397 *cp = '\0'; 1398 if (cp == msg) 1399 break; 1400 } 1401 } 1402 1403 /** We got a log message: tell any interested control connections. */ 1404 void 1405 control_event_logmsg(int severity, log_domain_mask_t domain, const char *msg) 1406 { 1407 int event; 1408 1409 /* Don't even think of trying to add stuff to a buffer from a cpuworker 1410 * thread. (See #25987 for plan to fix.) */ 1411 if (! in_main_thread()) 1412 return; 1413 1414 if (disable_log_messages) 1415 return; 1416 1417 if (domain == LD_BUG && EVENT_IS_INTERESTING(EVENT_STATUS_GENERAL) && 1418 severity <= LOG_NOTICE) { 1419 char *esc = esc_for_log(msg); 1420 ++disable_log_messages; 1421 control_event_general_status(severity, "BUG REASON=%s", esc); 1422 --disable_log_messages; 1423 tor_free(esc); 1424 } 1425 1426 event = log_severity_to_event(severity); 1427 if (event >= 0 && EVENT_IS_INTERESTING(event)) { 1428 char *b = NULL; 1429 const char *s; 1430 if (strchr(msg, '\n')) { 1431 b = tor_strdup(msg); 1432 control_logmsg_strip_newlines(b); 1433 } 1434 switch (severity) { 1435 case LOG_DEBUG: s = "DEBUG"; break; 1436 case LOG_INFO: s = "INFO"; break; 1437 case LOG_NOTICE: s = "NOTICE"; break; 1438 case LOG_WARN: s = "WARN"; break; 1439 case LOG_ERR: s = "ERR"; break; 1440 default: s = "UnknownLogSeverity"; break; 1441 } 1442 ++disable_log_messages; 1443 send_control_event(event, "650 %s %s\r\n", s, b?b:msg); 1444 if (severity == LOG_ERR) { 1445 /* Force a flush, since we may be about to die horribly */ 1446 queued_events_flush_all(1); 1447 } 1448 --disable_log_messages; 1449 tor_free(b); 1450 } 1451 } 1452 1453 /** 1454 * Logging callback: called when there is a queued pending log callback. 1455 */ 1456 void 1457 control_event_logmsg_pending(void) 1458 { 1459 if (! in_main_thread()) { 1460 /* We can't handle this case yet, since we're using a 1461 * mainloop_event_t to invoke queued_events_flush_all. We ought to 1462 * use a different mechanism instead: see #25987. 1463 **/ 1464 return; 1465 } 1466 tor_assert(flush_queued_events_event); 1467 mainloop_event_activate(flush_queued_events_event); 1468 } 1469 1470 /** Called whenever we receive new router descriptors: tell any 1471 * interested control connections. <b>routers</b> is a list of 1472 * routerinfo_t's. 1473 */ 1474 int 1475 control_event_descriptors_changed(smartlist_t *routers) 1476 { 1477 char *msg; 1478 1479 if (!EVENT_IS_INTERESTING(EVENT_NEW_DESC)) 1480 return 0; 1481 1482 { 1483 smartlist_t *names = smartlist_new(); 1484 char *ids; 1485 SMARTLIST_FOREACH(routers, routerinfo_t *, ri, { 1486 char *b = tor_malloc(MAX_VERBOSE_NICKNAME_LEN+1); 1487 router_get_verbose_nickname(b, ri); 1488 smartlist_add(names, b); 1489 }); 1490 ids = smartlist_join_strings(names, " ", 0, NULL); 1491 tor_asprintf(&msg, "650 NEWDESC %s\r\n", ids); 1492 send_control_event_string(EVENT_NEW_DESC, msg); 1493 tor_free(ids); 1494 tor_free(msg); 1495 SMARTLIST_FOREACH(names, char *, cp, tor_free(cp)); 1496 smartlist_free(names); 1497 } 1498 return 0; 1499 } 1500 1501 /** Called when an address mapping on <b>from</b> from changes to <b>to</b>. 1502 * <b>expires</b> values less than 3 are special; see connection_edge.c. If 1503 * <b>error</b> is non-NULL, it is an error code describing the failure 1504 * mode of the mapping. 1505 */ 1506 int 1507 control_event_address_mapped(const char *from, const char *to, 1508 time_t expires, const char *error, 1509 const int cached, uint64_t stream_id) 1510 { 1511 char *stream_id_str = NULL; 1512 if (!EVENT_IS_INTERESTING(EVENT_ADDRMAP)) 1513 return 0; 1514 1515 if (stream_id) { 1516 tor_asprintf(&stream_id_str, " STREAMID=%"PRIu64"", stream_id); 1517 } 1518 1519 if (expires < 3 || expires == TIME_MAX) 1520 send_control_event(EVENT_ADDRMAP, 1521 "650 ADDRMAP %s %s NEVER %s%s" 1522 "CACHED=\"%s\"%s\r\n", 1523 from, to, error ? error : "", error ? " " : "", 1524 cached ? "YES" : "NO", 1525 stream_id ? stream_id_str : ""); 1526 else { 1527 char buf[ISO_TIME_LEN+1]; 1528 char buf2[ISO_TIME_LEN+1]; 1529 format_local_iso_time(buf,expires); 1530 format_iso_time(buf2,expires); 1531 send_control_event(EVENT_ADDRMAP, 1532 "650 ADDRMAP %s %s \"%s\" %s%sEXPIRES=\"%s\" " 1533 "CACHED=\"%s\"%s\r\n", 1534 from, to, buf, error ? error : "", 1535 error ? " " : "", buf2, cached ? "YES" : "NO", 1536 stream_id ? stream_id_str: ""); 1537 } 1538 1539 tor_free(stream_id_str); 1540 1541 return 0; 1542 } 1543 /** The network liveness has changed; this is called from circuitstats.c 1544 * whenever we receive a cell, or when timeout expires and we assume the 1545 * network is down. */ 1546 int 1547 control_event_network_liveness_update(int liveness) 1548 { 1549 if (liveness > 0) { 1550 if (get_cached_network_liveness() <= 0) { 1551 /* Update cached liveness */ 1552 set_cached_network_liveness(1); 1553 log_debug(LD_CONTROL, "Sending NETWORK_LIVENESS UP"); 1554 send_control_event_string(EVENT_NETWORK_LIVENESS, 1555 "650 NETWORK_LIVENESS UP\r\n"); 1556 } 1557 /* else was already live, no-op */ 1558 } else { 1559 if (get_cached_network_liveness() > 0) { 1560 /* Update cached liveness */ 1561 set_cached_network_liveness(0); 1562 log_debug(LD_CONTROL, "Sending NETWORK_LIVENESS DOWN"); 1563 send_control_event_string(EVENT_NETWORK_LIVENESS, 1564 "650 NETWORK_LIVENESS DOWN\r\n"); 1565 } 1566 /* else was already dead, no-op */ 1567 } 1568 1569 return 0; 1570 } 1571 1572 /** Helper function for NS-style events. Constructs and sends an event 1573 * of type <b>event</b> with string <b>event_string</b> out of the set of 1574 * networkstatuses <b>statuses</b>. Currently it is used for NS events 1575 * and NEWCONSENSUS events. */ 1576 static int 1577 control_event_networkstatus_changed_helper(smartlist_t *statuses, 1578 uint16_t event, 1579 const char *event_string) 1580 { 1581 smartlist_t *strs; 1582 char *s, *esc = NULL; 1583 if (!EVENT_IS_INTERESTING(event) || !smartlist_len(statuses)) 1584 return 0; 1585 1586 strs = smartlist_new(); 1587 smartlist_add_strdup(strs, "650+"); 1588 smartlist_add_strdup(strs, event_string); 1589 smartlist_add_strdup(strs, "\r\n"); 1590 SMARTLIST_FOREACH(statuses, const routerstatus_t *, rs, 1591 { 1592 s = networkstatus_getinfo_helper_single(rs); 1593 if (!s) continue; 1594 smartlist_add(strs, s); 1595 }); 1596 1597 s = smartlist_join_strings(strs, "", 0, NULL); 1598 write_escaped_data(s, strlen(s), &esc); 1599 SMARTLIST_FOREACH(strs, char *, cp, tor_free(cp)); 1600 smartlist_free(strs); 1601 tor_free(s); 1602 send_control_event_string(event, esc); 1603 send_control_event_string(event, 1604 "650 OK\r\n"); 1605 1606 tor_free(esc); 1607 return 0; 1608 } 1609 1610 /** Called when the routerstatus_ts <b>statuses</b> have changed: sends 1611 * an NS event to any controller that cares. */ 1612 int 1613 control_event_networkstatus_changed(smartlist_t *statuses) 1614 { 1615 return control_event_networkstatus_changed_helper(statuses, EVENT_NS, "NS"); 1616 } 1617 1618 /** Called when we get a new consensus networkstatus. Sends a NEWCONSENSUS 1619 * event consisting of an NS-style line for each relay in the consensus. */ 1620 int 1621 control_event_newconsensus(const networkstatus_t *consensus) 1622 { 1623 if (!control_event_is_interesting(EVENT_NEWCONSENSUS)) 1624 return 0; 1625 return control_event_networkstatus_changed_helper( 1626 consensus->routerstatus_list, EVENT_NEWCONSENSUS, "NEWCONSENSUS"); 1627 } 1628 1629 /** Called when we compute a new circuitbuildtimeout */ 1630 int 1631 control_event_buildtimeout_set(buildtimeout_set_event_t type, 1632 const char *args) 1633 { 1634 const char *type_string = NULL; 1635 1636 if (!control_event_is_interesting(EVENT_BUILDTIMEOUT_SET)) 1637 return 0; 1638 1639 switch (type) { 1640 case BUILDTIMEOUT_SET_EVENT_COMPUTED: 1641 type_string = "COMPUTED"; 1642 break; 1643 case BUILDTIMEOUT_SET_EVENT_RESET: 1644 type_string = "RESET"; 1645 break; 1646 case BUILDTIMEOUT_SET_EVENT_SUSPENDED: 1647 type_string = "SUSPENDED"; 1648 break; 1649 case BUILDTIMEOUT_SET_EVENT_DISCARD: 1650 type_string = "DISCARD"; 1651 break; 1652 case BUILDTIMEOUT_SET_EVENT_RESUME: 1653 type_string = "RESUME"; 1654 break; 1655 default: 1656 type_string = "UNKNOWN"; 1657 break; 1658 } 1659 1660 send_control_event(EVENT_BUILDTIMEOUT_SET, 1661 "650 BUILDTIMEOUT_SET %s %s\r\n", 1662 type_string, args); 1663 1664 return 0; 1665 } 1666 1667 /** Called when a signal has been processed from signal_callback */ 1668 int 1669 control_event_signal(uintptr_t signal_num) 1670 { 1671 const char *signal_string = NULL; 1672 1673 if (!control_event_is_interesting(EVENT_GOT_SIGNAL)) 1674 return 0; 1675 1676 for (unsigned i = 0; signal_table[i].signal_name != NULL; ++i) { 1677 if ((int)signal_num == signal_table[i].sig) { 1678 signal_string = signal_table[i].signal_name; 1679 break; 1680 } 1681 } 1682 1683 if (signal_string == NULL) { 1684 log_warn(LD_BUG, "Unrecognized signal %lu in control_event_signal", 1685 (unsigned long)signal_num); 1686 return -1; 1687 } 1688 1689 send_control_event(EVENT_GOT_SIGNAL, "650 SIGNAL %s\r\n", 1690 signal_string); 1691 return 0; 1692 } 1693 1694 /** Called when a single local_routerstatus_t has changed: Sends an NS event 1695 * to any controller that cares. */ 1696 int 1697 control_event_networkstatus_changed_single(const routerstatus_t *rs) 1698 { 1699 smartlist_t *statuses; 1700 int r; 1701 1702 if (!EVENT_IS_INTERESTING(EVENT_NS)) 1703 return 0; 1704 1705 statuses = smartlist_new(); 1706 smartlist_add(statuses, (void*)rs); 1707 r = control_event_networkstatus_changed(statuses); 1708 smartlist_free(statuses); 1709 return r; 1710 } 1711 1712 /** Our own router descriptor has changed; tell any controllers that care. 1713 */ 1714 int 1715 control_event_my_descriptor_changed(void) 1716 { 1717 send_control_event(EVENT_DESCCHANGED, "650 DESCCHANGED\r\n"); 1718 return 0; 1719 } 1720 1721 /** Helper: sends a status event where <b>type</b> is one of 1722 * EVENT_STATUS_{GENERAL,CLIENT,SERVER}, where <b>severity</b> is one of 1723 * LOG_{NOTICE,WARN,ERR}, and where <b>format</b> is a printf-style format 1724 * string corresponding to <b>args</b>. */ 1725 static int 1726 control_event_status(int type, int severity, const char *format, va_list args) 1727 { 1728 char *user_buf = NULL; 1729 char format_buf[160]; 1730 const char *status, *sev; 1731 1732 switch (type) { 1733 case EVENT_STATUS_GENERAL: 1734 status = "STATUS_GENERAL"; 1735 break; 1736 case EVENT_STATUS_CLIENT: 1737 status = "STATUS_CLIENT"; 1738 break; 1739 case EVENT_STATUS_SERVER: 1740 status = "STATUS_SERVER"; 1741 break; 1742 default: 1743 log_warn(LD_BUG, "Unrecognized status type %d", type); 1744 return -1; 1745 } 1746 switch (severity) { 1747 case LOG_NOTICE: 1748 sev = "NOTICE"; 1749 break; 1750 case LOG_WARN: 1751 sev = "WARN"; 1752 break; 1753 case LOG_ERR: 1754 sev = "ERR"; 1755 break; 1756 default: 1757 log_warn(LD_BUG, "Unrecognized status severity %d", severity); 1758 return -1; 1759 } 1760 if (tor_snprintf(format_buf, sizeof(format_buf), "650 %s %s", 1761 status, sev)<0) { 1762 log_warn(LD_BUG, "Format string too long."); 1763 return -1; 1764 } 1765 if (tor_vasprintf(&user_buf, format, args)<0) { 1766 log_warn(LD_BUG, "Failed to create user buffer."); 1767 return -1; 1768 } 1769 1770 send_control_event(type, "%s %s\r\n", format_buf, user_buf); 1771 tor_free(user_buf); 1772 return 0; 1773 } 1774 1775 #ifndef COCCI 1776 #define CONTROL_EVENT_STATUS_BODY(event, sev) \ 1777 int r; \ 1778 do { \ 1779 va_list ap; \ 1780 if (!EVENT_IS_INTERESTING(event)) \ 1781 return 0; \ 1782 \ 1783 va_start(ap, format); \ 1784 r = control_event_status((event), (sev), format, ap); \ 1785 va_end(ap); \ 1786 } while (0) 1787 #endif /* !defined(COCCI) */ 1788 1789 /** Format and send an EVENT_STATUS_GENERAL event whose main text is obtained 1790 * by formatting the arguments using the printf-style <b>format</b>. */ 1791 int 1792 control_event_general_status(int severity, const char *format, ...) 1793 { 1794 CONTROL_EVENT_STATUS_BODY(EVENT_STATUS_GENERAL, severity); 1795 return r; 1796 } 1797 1798 /** Format and send an EVENT_STATUS_GENERAL LOG_ERR event, and flush it to the 1799 * controller(s) immediately. */ 1800 int 1801 control_event_general_error(const char *format, ...) 1802 { 1803 CONTROL_EVENT_STATUS_BODY(EVENT_STATUS_GENERAL, LOG_ERR); 1804 /* Force a flush, since we may be about to die horribly */ 1805 queued_events_flush_all(1); 1806 return r; 1807 } 1808 1809 /** Format and send an EVENT_STATUS_CLIENT event whose main text is obtained 1810 * by formatting the arguments using the printf-style <b>format</b>. */ 1811 int 1812 control_event_client_status(int severity, const char *format, ...) 1813 { 1814 CONTROL_EVENT_STATUS_BODY(EVENT_STATUS_CLIENT, severity); 1815 return r; 1816 } 1817 1818 /** Format and send an EVENT_STATUS_CLIENT LOG_ERR event, and flush it to the 1819 * controller(s) immediately. */ 1820 int 1821 control_event_client_error(const char *format, ...) 1822 { 1823 CONTROL_EVENT_STATUS_BODY(EVENT_STATUS_CLIENT, LOG_ERR); 1824 /* Force a flush, since we may be about to die horribly */ 1825 queued_events_flush_all(1); 1826 return r; 1827 } 1828 1829 /** Format and send an EVENT_STATUS_SERVER event whose main text is obtained 1830 * by formatting the arguments using the printf-style <b>format</b>. */ 1831 int 1832 control_event_server_status(int severity, const char *format, ...) 1833 { 1834 CONTROL_EVENT_STATUS_BODY(EVENT_STATUS_SERVER, severity); 1835 return r; 1836 } 1837 1838 /** Format and send an EVENT_STATUS_SERVER LOG_ERR event, and flush it to the 1839 * controller(s) immediately. */ 1840 int 1841 control_event_server_error(const char *format, ...) 1842 { 1843 CONTROL_EVENT_STATUS_BODY(EVENT_STATUS_SERVER, LOG_ERR); 1844 /* Force a flush, since we may be about to die horribly */ 1845 queued_events_flush_all(1); 1846 return r; 1847 } 1848 1849 /** Called when the status of an entry guard with the given <b>nickname</b> 1850 * and identity <b>digest</b> has changed to <b>status</b>: tells any 1851 * controllers that care. */ 1852 int 1853 control_event_guard(const char *nickname, const char *digest, 1854 const char *status) 1855 { 1856 char hbuf[HEX_DIGEST_LEN+1]; 1857 base16_encode(hbuf, sizeof(hbuf), digest, DIGEST_LEN); 1858 if (!EVENT_IS_INTERESTING(EVENT_GUARD)) 1859 return 0; 1860 1861 { 1862 char buf[MAX_VERBOSE_NICKNAME_LEN+1]; 1863 const node_t *node = node_get_by_id(digest); 1864 if (node) { 1865 node_get_verbose_nickname(node, buf); 1866 } else { 1867 tor_snprintf(buf, sizeof(buf), "$%s~%s", hbuf, nickname); 1868 } 1869 send_control_event(EVENT_GUARD, 1870 "650 GUARD ENTRY %s %s\r\n", buf, status); 1871 } 1872 return 0; 1873 } 1874 1875 /** Called when a configuration option changes. This is generally triggered 1876 * by SETCONF requests and RELOAD/SIGHUP signals. The <b>changes</b> are 1877 * a linked list of configuration key-values. 1878 * <b>changes</b> can be NULL, meaning "no changes". 1879 */ 1880 void 1881 control_event_conf_changed(const config_line_t *changes) 1882 { 1883 char *result; 1884 smartlist_t *lines; 1885 if (!EVENT_IS_INTERESTING(EVENT_CONF_CHANGED) || !changes) { 1886 return; 1887 } 1888 lines = smartlist_new(); 1889 for (const config_line_t *line = changes; line; line = line->next) { 1890 if (line->value == NULL) { 1891 smartlist_add_asprintf(lines, "650-%s", line->key); 1892 } else { 1893 smartlist_add_asprintf(lines, "650-%s=%s", line->key, line->value); 1894 } 1895 } 1896 result = smartlist_join_strings(lines, "\r\n", 0, NULL); 1897 send_control_event(EVENT_CONF_CHANGED, 1898 "650-CONF_CHANGED\r\n%s\r\n650 OK\r\n", result); 1899 tor_free(result); 1900 SMARTLIST_FOREACH(lines, char *, cp, tor_free(cp)); 1901 smartlist_free(lines); 1902 } 1903 1904 /** We just generated a new summary of which countries we've seen clients 1905 * from recently. Send a copy to the controller in case it wants to 1906 * display it for the user. */ 1907 void 1908 control_event_clients_seen(const char *controller_str) 1909 { 1910 send_control_event(EVENT_CLIENTS_SEEN, 1911 "650 CLIENTS_SEEN %s\r\n", controller_str); 1912 } 1913 1914 /** A new pluggable transport called <b>transport_name</b> was 1915 * launched on <b>addr</b>:<b>port</b>. <b>mode</b> is either 1916 * "server" or "client" depending on the mode of the pluggable 1917 * transport. 1918 * "650" SP "TRANSPORT_LAUNCHED" SP Mode SP Name SP Address SP Port 1919 */ 1920 void 1921 control_event_transport_launched(const char *mode, const char *transport_name, 1922 tor_addr_t *addr, uint16_t port) 1923 { 1924 send_control_event(EVENT_TRANSPORT_LAUNCHED, 1925 "650 TRANSPORT_LAUNCHED %s %s %s %u\r\n", 1926 mode, transport_name, fmt_addr(addr), port); 1927 } 1928 1929 /** A pluggable transport called <b>pt_name</b> has emitted a log message 1930 * found in <b>message</b> at <b>severity</b> log level. */ 1931 void 1932 control_event_pt_log(const char *log) 1933 { 1934 send_control_event(EVENT_PT_LOG, 1935 "650 PT_LOG %s\r\n", 1936 log); 1937 } 1938 1939 /** A pluggable transport has emitted a STATUS message found in 1940 * <b>status</b>. */ 1941 void 1942 control_event_pt_status(const char *status) 1943 { 1944 send_control_event(EVENT_PT_STATUS, 1945 "650 PT_STATUS %s\r\n", 1946 status); 1947 } 1948 1949 /** Convert rendezvous auth type to string for HS_DESC control events 1950 */ 1951 const char * 1952 rend_auth_type_to_string(rend_auth_type_t auth_type) 1953 { 1954 const char *str; 1955 1956 switch (auth_type) { 1957 case REND_NO_AUTH: 1958 str = "NO_AUTH"; 1959 break; 1960 case REND_V3_AUTH: 1961 str = "REND_V3_AUTH"; 1962 break; 1963 default: 1964 str = "UNKNOWN"; 1965 } 1966 1967 return str; 1968 } 1969 1970 /** Return either the onion address if the given pointer is a non empty 1971 * string else the unknown string. */ 1972 static const char * 1973 rend_hsaddress_str_or_unknown(const char *onion_address) 1974 { 1975 static const char *str_unknown = "UNKNOWN"; 1976 const char *str_ret = str_unknown; 1977 1978 /* No valid pointer, unknown it is. */ 1979 if (!onion_address) { 1980 goto end; 1981 } 1982 /* Empty onion address thus we don't know, unknown it is. */ 1983 if (onion_address[0] == '\0') { 1984 goto end; 1985 } 1986 /* All checks are good so return the given onion address. */ 1987 str_ret = onion_address; 1988 1989 end: 1990 return str_ret; 1991 } 1992 1993 /** send HS_DESC requested event. 1994 * 1995 * <b>rend_query</b> is used to fetch requested onion address and auth type. 1996 * <b>hs_dir</b> is the description of contacting hs directory. 1997 * <b>desc_id_base32</b> is the ID of requested hs descriptor. 1998 * <b>hsdir_index</b> is the HSDir fetch index value for v3, an hex string. 1999 */ 2000 void 2001 control_event_hs_descriptor_requested(const char *onion_address, 2002 rend_auth_type_t auth_type, 2003 const char *id_digest, 2004 const char *desc_id, 2005 const char *hsdir_index) 2006 { 2007 char *hsdir_index_field = NULL; 2008 2009 if (BUG(!id_digest || !desc_id)) { 2010 return; 2011 } 2012 2013 if (hsdir_index) { 2014 tor_asprintf(&hsdir_index_field, " HSDIR_INDEX=%s", hsdir_index); 2015 } 2016 2017 send_control_event(EVENT_HS_DESC, 2018 "650 HS_DESC REQUESTED %s %s %s %s%s\r\n", 2019 rend_hsaddress_str_or_unknown(onion_address), 2020 rend_auth_type_to_string(auth_type), 2021 node_describe_longname_by_id(id_digest), 2022 desc_id, 2023 hsdir_index_field ? hsdir_index_field : ""); 2024 tor_free(hsdir_index_field); 2025 } 2026 2027 /** send HS_DESC CREATED event when a local service generates a descriptor. 2028 * 2029 * <b>onion_address</b> is service address. 2030 * <b>desc_id</b> is the descriptor ID. 2031 * <b>replica</b> is the the descriptor replica number. If it is negative, it 2032 * is ignored. 2033 */ 2034 void 2035 control_event_hs_descriptor_created(const char *onion_address, 2036 const char *desc_id, 2037 int replica) 2038 { 2039 char *replica_field = NULL; 2040 2041 if (BUG(!onion_address || !desc_id)) { 2042 return; 2043 } 2044 2045 if (replica >= 0) { 2046 tor_asprintf(&replica_field, " REPLICA=%d", replica); 2047 } 2048 2049 send_control_event(EVENT_HS_DESC, 2050 "650 HS_DESC CREATED %s UNKNOWN UNKNOWN %s%s\r\n", 2051 onion_address, desc_id, 2052 replica_field ? replica_field : ""); 2053 tor_free(replica_field); 2054 } 2055 2056 /** send HS_DESC upload event. 2057 * 2058 * <b>onion_address</b> is service address. 2059 * <b>hs_dir</b> is the description of contacting hs directory. 2060 * <b>desc_id</b> is the ID of requested hs descriptor. 2061 */ 2062 void 2063 control_event_hs_descriptor_upload(const char *onion_address, 2064 const char *id_digest, 2065 const char *desc_id, 2066 const char *hsdir_index) 2067 { 2068 char *hsdir_index_field = NULL; 2069 2070 if (BUG(!onion_address || !id_digest || !desc_id)) { 2071 return; 2072 } 2073 2074 if (hsdir_index) { 2075 tor_asprintf(&hsdir_index_field, " HSDIR_INDEX=%s", hsdir_index); 2076 } 2077 2078 send_control_event(EVENT_HS_DESC, 2079 "650 HS_DESC UPLOAD %s UNKNOWN %s %s%s\r\n", 2080 onion_address, 2081 node_describe_longname_by_id(id_digest), 2082 desc_id, 2083 hsdir_index_field ? hsdir_index_field : ""); 2084 tor_free(hsdir_index_field); 2085 } 2086 2087 /** send HS_DESC event after got response from hs directory. 2088 * 2089 * NOTE: this is an internal function used by following functions: 2090 * control_event_hsv3_descriptor_failed 2091 * 2092 * So do not call this function directly. 2093 */ 2094 static void 2095 event_hs_descriptor_receive_end(const char *action, 2096 const char *onion_address, 2097 const char *desc_id, 2098 rend_auth_type_t auth_type, 2099 const char *hsdir_id_digest, 2100 const char *reason) 2101 { 2102 char *reason_field = NULL; 2103 2104 if (BUG(!action || !onion_address)) { 2105 return; 2106 } 2107 2108 if (reason) { 2109 tor_asprintf(&reason_field, " REASON=%s", reason); 2110 } 2111 2112 send_control_event(EVENT_HS_DESC, 2113 "650 HS_DESC %s %s %s %s%s%s\r\n", 2114 action, 2115 rend_hsaddress_str_or_unknown(onion_address), 2116 rend_auth_type_to_string(auth_type), 2117 hsdir_id_digest ? 2118 node_describe_longname_by_id(hsdir_id_digest) : 2119 "UNKNOWN", 2120 desc_id ? desc_id : "", 2121 reason_field ? reason_field : ""); 2122 2123 tor_free(reason_field); 2124 } 2125 2126 /** send HS_DESC event after got response from hs directory. 2127 * 2128 * NOTE: this is an internal function used by following functions: 2129 * control_event_hs_descriptor_uploaded 2130 * control_event_hs_descriptor_upload_failed 2131 * 2132 * So do not call this function directly. 2133 */ 2134 void 2135 control_event_hs_descriptor_upload_end(const char *action, 2136 const char *onion_address, 2137 const char *id_digest, 2138 const char *reason) 2139 { 2140 char *reason_field = NULL; 2141 2142 if (BUG(!action || !id_digest)) { 2143 return; 2144 } 2145 2146 if (reason) { 2147 tor_asprintf(&reason_field, " REASON=%s", reason); 2148 } 2149 2150 send_control_event(EVENT_HS_DESC, 2151 "650 HS_DESC %s %s UNKNOWN %s%s\r\n", 2152 action, 2153 rend_hsaddress_str_or_unknown(onion_address), 2154 node_describe_longname_by_id(id_digest), 2155 reason_field ? reason_field : ""); 2156 2157 tor_free(reason_field); 2158 } 2159 2160 /* Send HS_DESC RECEIVED event 2161 * 2162 * Called when we successfully received a hidden service descriptor. */ 2163 void 2164 control_event_hsv3_descriptor_received(const char *onion_address, 2165 const char *desc_id, 2166 const char *hsdir_id_digest) 2167 { 2168 char *desc_id_field = NULL; 2169 2170 if (BUG(!onion_address || !desc_id || !hsdir_id_digest)) { 2171 return; 2172 } 2173 2174 /* Because DescriptorID is an optional positional value, we need to add a 2175 * whitespace before in order to not be next to the HsDir value. */ 2176 tor_asprintf(&desc_id_field, " %s", desc_id); 2177 2178 event_hs_descriptor_receive_end("RECEIVED", onion_address, desc_id_field, 2179 REND_NO_AUTH, hsdir_id_digest, NULL); 2180 tor_free(desc_id_field); 2181 } 2182 2183 /** send HS_DESC UPLOADED event 2184 * 2185 * called when we successfully uploaded a hidden service descriptor. 2186 */ 2187 void 2188 control_event_hs_descriptor_uploaded(const char *id_digest, 2189 const char *onion_address) 2190 { 2191 if (BUG(!id_digest)) { 2192 return; 2193 } 2194 2195 control_event_hs_descriptor_upload_end("UPLOADED", onion_address, 2196 id_digest, NULL); 2197 } 2198 2199 /** Send HS_DESC event to inform controller that the query to 2200 * <b>onion_address</b> failed to retrieve hidden service descriptor 2201 * <b>desc_id</b> from directory identified by <b>hsdir_id_digest</b>. If 2202 * NULL, "UNKNOWN" is used. If <b>reason</b> is not NULL, add it to REASON= 2203 * field. */ 2204 void 2205 control_event_hsv3_descriptor_failed(const char *onion_address, 2206 const char *desc_id, 2207 const char *hsdir_id_digest, 2208 const char *reason) 2209 { 2210 char *desc_id_field = NULL; 2211 2212 if (BUG(!onion_address || !desc_id || !reason)) { 2213 return; 2214 } 2215 2216 /* Because DescriptorID is an optional positional value, we need to add a 2217 * whitespace before in order to not be next to the HsDir value. */ 2218 tor_asprintf(&desc_id_field, " %s", desc_id); 2219 2220 event_hs_descriptor_receive_end("FAILED", onion_address, desc_id_field, 2221 REND_NO_AUTH, hsdir_id_digest, reason); 2222 tor_free(desc_id_field); 2223 } 2224 2225 /** Send HS_DESC_CONTENT event after completion of a successful fetch 2226 * from hs directory. If <b>hsdir_id_digest</b> is NULL, it is replaced 2227 * by "UNKNOWN". If <b>content</b> is NULL, it is replaced by an empty 2228 * string. The <b>onion_address</b> or <b>desc_id</b> set to NULL will 2229 * not trigger the control event. */ 2230 void 2231 control_event_hs_descriptor_content(const char *onion_address, 2232 const char *desc_id, 2233 const char *hsdir_id_digest, 2234 const char *content) 2235 { 2236 static const char *event_name = "HS_DESC_CONTENT"; 2237 char *esc_content = NULL; 2238 2239 if (!onion_address || !desc_id) { 2240 log_warn(LD_BUG, "Called with onion_address==%p, desc_id==%p, ", 2241 onion_address, desc_id); 2242 return; 2243 } 2244 2245 if (content == NULL) { 2246 /* Point it to empty content so it can still be escaped. */ 2247 content = ""; 2248 } 2249 write_escaped_data(content, strlen(content), &esc_content); 2250 2251 send_control_event(EVENT_HS_DESC_CONTENT, 2252 "650+%s %s %s %s\r\n%s650 OK\r\n", 2253 event_name, 2254 rend_hsaddress_str_or_unknown(onion_address), 2255 desc_id, 2256 hsdir_id_digest ? 2257 node_describe_longname_by_id(hsdir_id_digest) : 2258 "UNKNOWN", 2259 esc_content); 2260 tor_free(esc_content); 2261 } 2262 2263 /** Send HS_DESC event to inform controller upload of hidden service 2264 * descriptor identified by <b>id_digest</b> failed. If <b>reason</b> 2265 * is not NULL, add it to REASON= field. 2266 */ 2267 void 2268 control_event_hs_descriptor_upload_failed(const char *id_digest, 2269 const char *onion_address, 2270 const char *reason) 2271 { 2272 if (BUG(!id_digest)) { 2273 return; 2274 } 2275 control_event_hs_descriptor_upload_end("FAILED", onion_address, 2276 id_digest, reason); 2277 } 2278 2279 void 2280 control_events_free_all(void) 2281 { 2282 smartlist_t *queued_events = NULL; 2283 2284 stats_prev_n_read = stats_prev_n_written = 0; 2285 2286 if (queued_control_events_lock) { 2287 tor_mutex_acquire(queued_control_events_lock); 2288 flush_queued_event_pending = 0; 2289 queued_events = queued_control_events; 2290 queued_control_events = NULL; 2291 tor_mutex_release(queued_control_events_lock); 2292 } 2293 if (queued_events) { 2294 SMARTLIST_FOREACH(queued_events, queued_event_t *, ev, 2295 queued_event_free(ev)); 2296 smartlist_free(queued_events); 2297 } 2298 if (flush_queued_events_event) { 2299 mainloop_event_free(flush_queued_events_event); 2300 flush_queued_events_event = NULL; 2301 } 2302 global_event_mask = 0; 2303 disable_log_messages = 0; 2304 } 2305 2306 #ifdef TOR_UNIT_TESTS 2307 /* For testing: change the value of global_event_mask */ 2308 void 2309 control_testing_set_global_event_mask(uint64_t mask) 2310 { 2311 global_event_mask = mask; 2312 } 2313 #endif /* defined(TOR_UNIT_TESTS) */