/** 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;
}
}
