/** Process a <b>cell</b> that was just received on <b>conn</b>. Keep internal * statistics about how many of each cell we've processed so far * this second, and the total number of microseconds it took to * process each type of cell. */ void command_process_var_cell(var_cell_t *cell, or_connection_t *conn) { #ifdef KEEP_TIMING_STATS /* how many of each cell have we seen so far this second? needs better * name. */ static int num_versions=0, num_cert=0; time_t now = time(NULL); if (now > current_second) { /* the second has rolled over */ /* print stats */ log_info(LD_OR, "At end of second: %d versions (%d ms), %d cert (%d ms)", num_versions, versions_time/1000, cert, cert_time/1000); num_versions = num_cert = 0; versions_time = cert_time = 0; /* remember which second it is, for next time */ current_second = now; } #endif /* reject all when not handshaking. */ if (conn->_base.state != OR_CONN_STATE_OR_HANDSHAKING) return; switch (cell->command) { case CELL_VERSIONS: ++stats_n_versions_cells_processed; PROCESS_CELL(versions, cell, conn); break; default: log_warn(LD_BUG, "Variable-length cell of unknown type (%d) received.", cell->command); tor_fragile_assert(); break; } }
/** Process a <b>cell</b> that was just received on <b>conn</b>. Keep internal * statistics about how many of each cell we've processed so far * this second, and the total number of microseconds it took to * process each type of cell. */ void command_process_var_cell(var_cell_t *cell, or_connection_t *conn) { #ifdef KEEP_TIMING_STATS /* how many of each cell have we seen so far this second? needs better * name. */ static int num_versions=0, num_certs=0; time_t now = time(NULL); if (now > current_second) { /* the second has rolled over */ /* print stats */ log_info(LD_OR, "At end of second: %d versions (%d ms), %d certs (%d ms)", num_versions, versions_time/1000, num_certs, certs_time/1000); num_versions = num_certs = 0; versions_time = certs_time = 0; /* remember which second it is, for next time */ current_second = now; } #endif if (conn->_base.marked_for_close) return; switch (conn->_base.state) { case OR_CONN_STATE_OR_HANDSHAKING_V2: if (cell->command != CELL_VERSIONS) return; break; case OR_CONN_STATE_TLS_HANDSHAKING: /* If we're using bufferevents, it's entirely possible for us to * notice "hey, data arrived!" before we notice "hey, the handshake * finished!" And we need to be accepting both at once to handle both * the v2 and v3 handshakes. */ /* fall through */ case OR_CONN_STATE_TLS_SERVER_RENEGOTIATING: if (! command_allowed_before_handshake(cell->command)) { log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL, "Received a cell with command %d in state %s; " "ignoring it.", (int)cell->command, conn_state_to_string(CONN_TYPE_OR,conn->_base.state)); return; } else { if (enter_v3_handshake_with_cell(cell, conn)<0) return; } break; case OR_CONN_STATE_OR_HANDSHAKING_V3: if (cell->command != CELL_AUTHENTICATE) or_handshake_state_record_var_cell(conn->handshake_state, cell, 1); break; /* Everything is allowed */ case OR_CONN_STATE_OPEN: if (conn->link_proto < 3) { log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL, "Received a variable-length cell with command %d in state %s " "with link protocol %d; ignoring it.", (int)cell->command, conn_state_to_string(CONN_TYPE_OR,conn->_base.state), (int)conn->link_proto); return; } break; default: log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL, "Received var-length cell with command %d in unexpected state " "%s [%d]; ignoring it.", (int)cell->command, conn_state_to_string(CONN_TYPE_OR,conn->_base.state), (int)conn->_base.state); return; } switch (cell->command) { case CELL_VERSIONS: ++stats_n_versions_cells_processed; PROCESS_CELL(versions, cell, conn); break; case CELL_VPADDING: ++stats_n_vpadding_cells_processed; /* Do nothing */ break; case CELL_CERTS: ++stats_n_certs_cells_processed; PROCESS_CELL(certs, cell, conn); break; case CELL_AUTH_CHALLENGE: ++stats_n_auth_challenge_cells_processed; PROCESS_CELL(auth_challenge, cell, conn); break; case CELL_AUTHENTICATE: ++stats_n_authenticate_cells_processed; PROCESS_CELL(authenticate, cell, conn); break; case CELL_AUTHORIZE: ++stats_n_authorize_cells_processed; /* Ignored so far. */ break; default: log_fn(LOG_INFO, LD_PROTOCOL, "Variable-length cell of unknown type (%d) received.", cell->command); break; } }
/** Process a <b>cell</b> that was just received on <b>conn</b>. Keep internal * statistics about how many of each cell we've processed so far * this second, and the total number of microseconds it took to * process each type of cell. */ void command_process_cell(cell_t *cell, or_connection_t *conn) { int handshaking = (conn->_base.state != OR_CONN_STATE_OPEN); #ifdef KEEP_TIMING_STATS /* how many of each cell have we seen so far this second? needs better * name. */ static int num_create=0, num_created=0, num_relay=0, num_destroy=0; /* how long has it taken to process each type of cell? */ static int create_time=0, created_time=0, relay_time=0, destroy_time=0; static time_t current_second = 0; /* from previous calls to time */ time_t now = time(NULL); if (now > current_second) { /* the second has rolled over */ /* print stats */ log_info(LD_OR, "At end of second: %d creates (%d ms), %d createds (%d ms), " "%d relays (%d ms), %d destroys (%d ms)", num_create, create_time/1000, num_created, created_time/1000, num_relay, relay_time/1000, num_destroy, destroy_time/1000); /* zero out stats */ num_create = num_created = num_relay = num_destroy = 0; create_time = created_time = relay_time = destroy_time = 0; /* remember which second it is, for next time */ current_second = now; } #endif #ifdef KEEP_TIMING_STATS #define PROCESS_CELL(tp, cl, cn) STMT_BEGIN { \ ++num ## tp; \ command_time_process_cell(cl, cn, & tp ## time , \ command_process_ ## tp ## _cell); \ } STMT_END #else #define PROCESS_CELL(tp, cl, cn) command_process_ ## tp ## _cell(cl, cn) #endif if (conn->_base.marked_for_close) return; /* Reject all but VERSIONS and NETINFO when handshaking. */ /* (VERSIONS should actually be impossible; it's variable-length.) */ if (handshaking && cell->command != CELL_VERSIONS && cell->command != CELL_NETINFO) { log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL, "Received unexpected cell command %d in state %s; ignoring it.", (int)cell->command, conn_state_to_string(CONN_TYPE_OR,conn->_base.state)); return; } if (conn->_base.state == OR_CONN_STATE_OR_HANDSHAKING_V3) or_handshake_state_record_cell(conn->handshake_state, cell, 1); switch (cell->command) { case CELL_PADDING: ++stats_n_padding_cells_processed; /* do nothing */ break; case CELL_CREATE: case CELL_CREATE_FAST: ++stats_n_create_cells_processed; PROCESS_CELL(create, cell, conn); break; case CELL_CREATED: case CELL_CREATED_FAST: ++stats_n_created_cells_processed; PROCESS_CELL(created, cell, conn); break; case CELL_RELAY: case CELL_RELAY_EARLY: ++stats_n_relay_cells_processed; PROCESS_CELL(relay, cell, conn); break; case CELL_DESTROY: ++stats_n_destroy_cells_processed; PROCESS_CELL(destroy, cell, conn); break; case CELL_VERSIONS: tor_fragile_assert(); break; case CELL_NETINFO: ++stats_n_netinfo_cells_processed; PROCESS_CELL(netinfo, cell, conn); break; default: log_fn(LOG_INFO, LD_PROTOCOL, "Cell of unknown type (%d) received. Dropping.", cell->command); break; } }
/** Process a <b>cell</b> that was just received on <b>chan</b>. Keep internal * statistics about how many of each cell we've processed so far * this second, and the total number of microseconds it took to * process each type of cell. */ void command_process_cell(channel_t *chan, cell_t *cell) { #ifdef KEEP_TIMING_STATS /* how many of each cell have we seen so far this second? needs better * name. */ static int num_create=0, num_created=0, num_relay=0, num_destroy=0; /* how long has it taken to process each type of cell? */ static int create_time=0, created_time=0, relay_time=0, destroy_time=0; static time_t current_second = 0; /* from previous calls to time */ time_t now = time(NULL); if (now > current_second) { /* the second has rolled over */ /* print stats */ log_info(LD_OR, "At end of second: %d creates (%d ms), %d createds (%d ms), " "%d relays (%d ms), %d destroys (%d ms)", num_create, create_time/1000, num_created, created_time/1000, num_relay, relay_time/1000, num_destroy, destroy_time/1000); /* zero out stats */ num_create = num_created = num_relay = num_destroy = 0; create_time = created_time = relay_time = destroy_time = 0; /* remember which second it is, for next time */ current_second = now; } #endif #ifdef KEEP_TIMING_STATS #define PROCESS_CELL(tp, cl, cn) STMT_BEGIN { \ ++num ## tp; \ command_time_process_cell(cl, cn, & tp ## time , \ command_process_ ## tp ## _cell); \ } STMT_END #else #define PROCESS_CELL(tp, cl, cn) command_process_ ## tp ## _cell(cl, cn) #endif switch (cell->command) { case CELL_CREATE: case CELL_CREATE_FAST: ++stats_n_create_cells_processed; PROCESS_CELL(create, cell, chan); break; case CELL_CREATED: case CELL_CREATED_FAST: ++stats_n_created_cells_processed; PROCESS_CELL(created, cell, chan); break; case CELL_RELAY: case CELL_RELAY_EARLY: ++stats_n_relay_cells_processed; PROCESS_CELL(relay, cell, chan); break; case CELL_DESTROY: ++stats_n_destroy_cells_processed; PROCESS_CELL(destroy, cell, chan); break; default: log_fn(LOG_INFO, LD_PROTOCOL, "Cell of unknown or unexpected type (%d) received. " "Dropping.", cell->command); break; } }