/** Read stored accounting information from disk. Return 0 on success; * return -1 and change nothing on failure. */ static int read_bandwidth_usage(void) { or_state_t *state = get_or_state(); { char *fname = get_datadir_fname("bw_accounting"); unlink(fname); tor_free(fname); } if (!state) return -1; log_info(LD_ACCT, "Reading bandwidth accounting data from state file"); n_bytes_read_in_interval = state->AccountingBytesReadInInterval; n_bytes_written_in_interval = state->AccountingBytesWrittenInInterval; n_seconds_active_in_interval = state->AccountingSecondsActive; interval_start_time = state->AccountingIntervalStart; expected_bandwidth_usage = state->AccountingExpectedUsage; /* Older versions of Tor (before 0.2.2.17-alpha or so) didn't generate these * fields. If you switch back and forth, you might get an * AccountingSoftLimitHitAt value from long before the most recent * interval_start_time. If that's so, then ignore the softlimit-related * values. */ if (state->AccountingSoftLimitHitAt > interval_start_time) { soft_limit_hit_at = state->AccountingSoftLimitHitAt; n_bytes_at_soft_limit = state->AccountingBytesAtSoftLimit; n_seconds_to_hit_soft_limit = state->AccountingSecondsToReachSoftLimit; } else { soft_limit_hit_at = 0; n_bytes_at_soft_limit = 0; n_seconds_to_hit_soft_limit = 0; } { char tbuf1[ISO_TIME_LEN+1]; char tbuf2[ISO_TIME_LEN+1]; format_iso_time(tbuf1, state->LastWritten); format_iso_time(tbuf2, state->AccountingIntervalStart); log_info(LD_ACCT, "Successfully read bandwidth accounting info from state written at %s " "for interval starting at %s. We have been active for %lu seconds in " "this interval. At the start of the interval, we expected to use " "about %lu KB per second. ("U64_FORMAT" bytes read so far, " U64_FORMAT" bytes written so far)", tbuf1, tbuf2, (unsigned long)n_seconds_active_in_interval, (unsigned long)(expected_bandwidth_usage*1024/60), U64_PRINTF_ARG(n_bytes_read_in_interval), U64_PRINTF_ARG(n_bytes_written_in_interval)); } return 0; }
/*FFFF uses Tor logging functions. */ void mp_pool_log_status(mp_pool_t *pool, int severity) { uint64_t bytes_used = 0; uint64_t bytes_allocated = 0; uint64_t bu = 0, ba = 0; mp_chunk_t *chunk; int n_full = 0, n_used = 0; ASSERT(pool); for (chunk = pool->empty_chunks; chunk; chunk = chunk->next) { bytes_allocated += chunk->mem_size; } log_fn(severity, LD_MM, U64_FORMAT" bytes in %d empty chunks", U64_PRINTF_ARG(bytes_allocated), pool->n_empty_chunks); for (chunk = pool->used_chunks; chunk; chunk = chunk->next) { ++n_used; bu += chunk->n_allocated * pool->item_alloc_size; ba += chunk->mem_size; log_fn(severity, LD_MM, " used chunk: %d items allocated", chunk->n_allocated); } log_fn(severity, LD_MM, U64_FORMAT"/"U64_FORMAT " bytes in %d partially full chunks", U64_PRINTF_ARG(bu), U64_PRINTF_ARG(ba), n_used); bytes_used += bu; bytes_allocated += ba; bu = ba = 0; for (chunk = pool->full_chunks; chunk; chunk = chunk->next) { ++n_full; bu += chunk->n_allocated * pool->item_alloc_size; ba += chunk->mem_size; } log_fn(severity, LD_MM, U64_FORMAT"/"U64_FORMAT " bytes in %d full chunks", U64_PRINTF_ARG(bu), U64_PRINTF_ARG(ba), n_full); bytes_used += bu; bytes_allocated += ba; log_fn(severity, LD_MM, "Total: "U64_FORMAT"/"U64_FORMAT" bytes allocated " "for cell pools are full.", U64_PRINTF_ARG(bytes_used), U64_PRINTF_ARG(bytes_allocated)); #ifdef MEMPOOL_STATS log_fn(severity, LD_MM, U64_FORMAT" cell allocations ever; " U64_FORMAT" chunk allocations ever; " U64_FORMAT" chunk frees ever.", U64_PRINTF_ARG(pool->total_items_allocated), U64_PRINTF_ARG(pool->total_chunks_allocated), U64_PRINTF_ARG(pool->total_chunks_freed)); #endif }
/** Read stored accounting information from disk. Return 0 on success; * return -1 and change nothing on failure. */ static int read_bandwidth_usage(void) { or_state_t *state = get_or_state(); { char *fname = get_datadir_fname("bw_accounting"); unlink(fname); tor_free(fname); } if (!state) return -1; /* Okay; it looks like the state file is more up-to-date than the * bw_accounting file, or the bw_accounting file is nonexistent, * or the bw_accounting file is corrupt. */ log_info(LD_ACCT, "Reading bandwidth accounting data from state file"); n_bytes_read_in_interval = state->AccountingBytesReadInInterval; n_bytes_written_in_interval = state->AccountingBytesWrittenInInterval; n_seconds_active_in_interval = state->AccountingSecondsActive; interval_start_time = state->AccountingIntervalStart; expected_bandwidth_usage = state->AccountingExpectedUsage; { char tbuf1[ISO_TIME_LEN+1]; char tbuf2[ISO_TIME_LEN+1]; format_iso_time(tbuf1, state->LastWritten); format_iso_time(tbuf2, state->AccountingIntervalStart); log_info(LD_ACCT, "Successfully read bandwidth accounting info from state written at %s " "for interval starting at %s. We have been active for %lu seconds in " "this interval. At the start of the interval, we expected to use " "about %lu KB per second. ("U64_FORMAT" bytes read so far, " U64_FORMAT" bytes written so far)", tbuf1, tbuf2, (unsigned long)n_seconds_active_in_interval, (unsigned long)(expected_bandwidth_usage*1024/60), U64_PRINTF_ARG(n_bytes_read_in_interval), U64_PRINTF_ARG(n_bytes_written_in_interval)); } return 0; }
/** Helper function: called when we get a GETINFO request for an * accounting-related key on the control connection <b>conn</b>. If we can * answer the request for <b>question</b>, then set *<b>answer</b> to a newly * allocated string holding the result. Otherwise, set *<b>answer</b> to * NULL. */ int getinfo_helper_accounting(control_connection_t *conn, const char *question, char **answer, const char **errmsg) { (void) conn; (void) errmsg; if (!strcmp(question, "accounting/enabled")) { *answer = tor_strdup(accounting_is_enabled(get_options()) ? "1" : "0"); } else if (!strcmp(question, "accounting/hibernating")) { if (hibernate_state == HIBERNATE_STATE_DORMANT) *answer = tor_strdup("hard"); else if (hibernate_state == HIBERNATE_STATE_LOWBANDWIDTH) *answer = tor_strdup("soft"); else *answer = tor_strdup("awake"); } else if (!strcmp(question, "accounting/bytes")) { *answer = tor_malloc(32); tor_snprintf(*answer, 32, U64_FORMAT" "U64_FORMAT, U64_PRINTF_ARG(n_bytes_read_in_interval), U64_PRINTF_ARG(n_bytes_written_in_interval)); } else if (!strcmp(question, "accounting/bytes-left")) { uint64_t limit = get_options()->AccountingMax; uint64_t read_left = 0, write_left = 0; if (n_bytes_read_in_interval < limit) read_left = limit - n_bytes_read_in_interval; if (n_bytes_written_in_interval < limit) write_left = limit - n_bytes_written_in_interval; *answer = tor_malloc(64); tor_snprintf(*answer, 64, U64_FORMAT" "U64_FORMAT, U64_PRINTF_ARG(read_left), U64_PRINTF_ARG(write_left)); } else if (!strcmp(question, "accounting/interval-start")) { *answer = tor_malloc(ISO_TIME_LEN+1); format_iso_time(*answer, interval_start_time); } else if (!strcmp(question, "accounting/interval-wake")) { *answer = tor_malloc(ISO_TIME_LEN+1); format_iso_time(*answer, interval_wakeup_time); } else if (!strcmp(question, "accounting/interval-end")) { *answer = tor_malloc(ISO_TIME_LEN+1); format_iso_time(*answer, interval_end_time); } else { *answer = NULL; } return 0; }
/** Process a 'create' <b>cell</b> that just arrived from <b>chan</b>. Make a * new circuit with the p_circ_id specified in cell. Put the circuit in state * onionskin_pending, and pass the onionskin to the cpuworker. Circ will get * picked up again when the cpuworker finishes decrypting it. */ static void command_process_create_cell(cell_t *cell, channel_t *chan) { or_circuit_t *circ; const or_options_t *options = get_options(); int id_is_high; tor_assert(cell); tor_assert(chan); log_debug(LD_OR, "Got a CREATE cell for circ_id %d on channel " U64_FORMAT " (%p)", cell->circ_id, U64_PRINTF_ARG(chan->global_identifier), chan); if (we_are_hibernating()) { log_info(LD_OR, "Received create cell but we're shutting down. Sending back " "destroy."); channel_send_destroy(cell->circ_id, chan, END_CIRC_REASON_HIBERNATING); return; } if (!server_mode(options) || (!public_server_mode(options) && channel_is_outgoing(chan))) { log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL, "Received create cell (type %d) from %s, but we're connected " "to it as a client. " "Sending back a destroy.", (int)cell->command, channel_get_canonical_remote_descr(chan)); channel_send_destroy(cell->circ_id, chan, END_CIRC_REASON_TORPROTOCOL); return; } /* If the high bit of the circuit ID is not as expected, close the * circ. */ id_is_high = cell->circ_id & (1<<15); if ((id_is_high && chan->circ_id_type == CIRC_ID_TYPE_HIGHER) || (!id_is_high && chan->circ_id_type == CIRC_ID_TYPE_LOWER)) { log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL, "Received create cell with unexpected circ_id %d. Closing.", cell->circ_id); channel_send_destroy(cell->circ_id, chan, END_CIRC_REASON_TORPROTOCOL); return; } if (circuit_id_in_use_on_channel(cell->circ_id, chan)) { const node_t *node = node_get_by_id(chan->identity_digest); log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL, "Received CREATE cell (circID %d) for known circ. " "Dropping (age %d).", cell->circ_id, (int)(time(NULL) - channel_when_created(chan))); if (node) { char *p = esc_for_log(node_get_platform(node)); log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL, "Details: router %s, platform %s.", node_describe(node), p); tor_free(p); } return; } circ = or_circuit_new(cell->circ_id, chan); circ->base_.purpose = CIRCUIT_PURPOSE_OR; circuit_set_state(TO_CIRCUIT(circ), CIRCUIT_STATE_ONIONSKIN_PENDING); if (cell->command == CELL_CREATE) { char *onionskin = tor_malloc(ONIONSKIN_CHALLENGE_LEN); memcpy(onionskin, cell->payload, ONIONSKIN_CHALLENGE_LEN); /* hand it off to the cpuworkers, and then return. */ if (assign_onionskin_to_cpuworker(NULL, circ, onionskin) < 0) { log_debug(LD_GENERAL,"Failed to hand off onionskin. Closing."); circuit_mark_for_close(TO_CIRCUIT(circ), END_CIRC_REASON_RESOURCELIMIT); return; } log_debug(LD_OR,"success: handed off onionskin."); } else { /* This is a CREATE_FAST cell; we can handle it immediately without using * a CPU worker. */ char keys[CPATH_KEY_MATERIAL_LEN]; char reply[DIGEST_LEN*2]; tor_assert(cell->command == CELL_CREATE_FAST); /* Make sure we never try to use the OR connection on which we * received this cell to satisfy an EXTEND request, */ channel_mark_client(chan); if (fast_server_handshake(cell->payload, (uint8_t*)reply, (uint8_t*)keys, sizeof(keys))<0) { log_warn(LD_OR,"Failed to generate key material. Closing."); circuit_mark_for_close(TO_CIRCUIT(circ), END_CIRC_REASON_INTERNAL); return; } if (onionskin_answer(circ, CELL_CREATED_FAST, reply, keys)<0) { log_warn(LD_OR,"Failed to reply to CREATE_FAST cell. Closing."); circuit_mark_for_close(TO_CIRCUIT(circ), END_CIRC_REASON_INTERNAL); return; } } }
/** Called when we get data from a cpuworker. If the answer is not complete, * wait for a complete answer. If the answer is complete, * process it as appropriate. */ int connection_cpu_process_inbuf(connection_t *conn) { uint64_t chan_id; circid_t circ_id; channel_t *p_chan = NULL; circuit_t *circ; tor_assert(conn); tor_assert(conn->type == CONN_TYPE_CPUWORKER); if (!connection_get_inbuf_len(conn)) return 0; if (conn->state == CPUWORKER_STATE_BUSY_ONION) { cpuworker_reply_t rpl; if (connection_get_inbuf_len(conn) < sizeof(cpuworker_reply_t)) return 0; /* not yet */ tor_assert(connection_get_inbuf_len(conn) == sizeof(cpuworker_reply_t)); connection_fetch_from_buf((void*)&rpl,sizeof(cpuworker_reply_t),conn); tor_assert(rpl.magic == CPUWORKER_REPLY_MAGIC); if (rpl.timed && rpl.success && rpl.handshake_type <= MAX_ONION_HANDSHAKE_TYPE) { /* Time how long this request took. The handshake_type check should be needless, but let's leave it in to be safe. */ struct timeval tv_end, tv_diff; int64_t usec_roundtrip; tor_gettimeofday(&tv_end); timersub(&tv_end, &rpl.started_at, &tv_diff); usec_roundtrip = ((int64_t)tv_diff.tv_sec)*1000000 + tv_diff.tv_usec; if (usec_roundtrip >= 0 && usec_roundtrip < MAX_BELIEVABLE_ONIONSKIN_DELAY) { ++onionskins_n_processed[rpl.handshake_type]; onionskins_usec_internal[rpl.handshake_type] += rpl.n_usec; onionskins_usec_roundtrip[rpl.handshake_type] += usec_roundtrip; if (onionskins_n_processed[rpl.handshake_type] >= 500000) { /* Scale down every 500000 handshakes. On a busy server, that's * less impressive than it sounds. */ onionskins_n_processed[rpl.handshake_type] /= 2; onionskins_usec_internal[rpl.handshake_type] /= 2; onionskins_usec_roundtrip[rpl.handshake_type] /= 2; } } } /* parse out the circ it was talking about */ tag_unpack(rpl.tag, &chan_id, &circ_id); circ = NULL; log_debug(LD_OR, "Unpacking cpuworker reply, chan_id is " U64_FORMAT ", circ_id is %u", U64_PRINTF_ARG(chan_id), (unsigned)circ_id); p_chan = channel_find_by_global_id(chan_id); if (p_chan) circ = circuit_get_by_circid_channel(circ_id, p_chan); if (rpl.success == 0) { log_debug(LD_OR, "decoding onionskin failed. " "(Old key or bad software.) Closing."); if (circ) circuit_mark_for_close(circ, END_CIRC_REASON_TORPROTOCOL); goto done_processing; } if (!circ) { /* This happens because somebody sends us a destroy cell and the * circuit goes away, while the cpuworker is working. This is also * why our tag doesn't include a pointer to the circ, because we'd * never know if it's still valid. */ log_debug(LD_OR,"processed onion for a circ that's gone. Dropping."); goto done_processing; } tor_assert(! CIRCUIT_IS_ORIGIN(circ)); if (onionskin_answer(TO_OR_CIRCUIT(circ), &rpl.created_cell, (const char*)rpl.keys, rpl.rend_auth_material) < 0) { log_warn(LD_OR,"onionskin_answer failed. Closing."); circuit_mark_for_close(circ, END_CIRC_REASON_INTERNAL); goto done_processing; } log_debug(LD_OR,"onionskin_answer succeeded. Yay."); } else { tor_assert(0); /* don't ask me to do handshakes yet */ } done_processing: conn->state = CPUWORKER_STATE_IDLE; num_cpuworkers_busy--; if (conn->timestamp_created < last_rotation_time) { connection_mark_for_close(conn); num_cpuworkers--; spawn_enough_cpuworkers(); } else { process_pending_task(conn); } return 0; }
/** Called when we get data from a cpuworker. If the answer is not complete, * wait for a complete answer. If the answer is complete, * process it as appropriate. */ int connection_cpu_process_inbuf(connection_t *conn) { char success; char buf[LEN_ONION_RESPONSE]; uint64_t chan_id; circid_t circ_id; channel_t *p_chan = NULL; circuit_t *circ; tor_assert(conn); tor_assert(conn->type == CONN_TYPE_CPUWORKER); if (!connection_get_inbuf_len(conn)) return 0; if (conn->state == CPUWORKER_STATE_BUSY_ONION) { if (connection_get_inbuf_len(conn) < LEN_ONION_RESPONSE) return 0; /* not yet */ tor_assert(connection_get_inbuf_len(conn) == LEN_ONION_RESPONSE); connection_fetch_from_buf(&success,1,conn); connection_fetch_from_buf(buf,LEN_ONION_RESPONSE-1,conn); /* parse out the circ it was talking about */ tag_unpack(buf, &chan_id, &circ_id); circ = NULL; log_debug(LD_OR, "Unpacking cpuworker reply, chan_id is " U64_FORMAT ", circ_id is %d", U64_PRINTF_ARG(chan_id), circ_id); p_chan = channel_find_by_global_id(chan_id); if (p_chan) circ = circuit_get_by_circid_channel(circ_id, p_chan); if (success == 0) { log_debug(LD_OR, "decoding onionskin failed. " "(Old key or bad software.) Closing."); if (circ) circuit_mark_for_close(circ, END_CIRC_REASON_TORPROTOCOL); goto done_processing; } if (!circ) { /* This happens because somebody sends us a destroy cell and the * circuit goes away, while the cpuworker is working. This is also * why our tag doesn't include a pointer to the circ, because we'd * never know if it's still valid. */ log_debug(LD_OR,"processed onion for a circ that's gone. Dropping."); goto done_processing; } tor_assert(! CIRCUIT_IS_ORIGIN(circ)); if (onionskin_answer(TO_OR_CIRCUIT(circ), CELL_CREATED, buf+TAG_LEN, buf+TAG_LEN+ONIONSKIN_REPLY_LEN) < 0) { log_warn(LD_OR,"onionskin_answer failed. Closing."); circuit_mark_for_close(circ, END_CIRC_REASON_INTERNAL); goto done_processing; } log_debug(LD_OR,"onionskin_answer succeeded. Yay."); } else { tor_assert(0); /* don't ask me to do handshakes yet */ } done_processing: conn->state = CPUWORKER_STATE_IDLE; num_cpuworkers_busy--; if (conn->timestamp_created < last_rotation_time) { connection_mark_for_close(conn); num_cpuworkers--; spawn_enough_cpuworkers(); } else { process_pending_task(conn); } return 0; }
/** Process a 'create' <b>cell</b> that just arrived from <b>chan</b>. Make a * new circuit with the p_circ_id specified in cell. Put the circuit in state * onionskin_pending, and pass the onionskin to the cpuworker. Circ will get * picked up again when the cpuworker finishes decrypting it. */ static void command_process_create_cell(cell_t *cell, channel_t *chan) { or_circuit_t *circ; const or_options_t *options = get_options(); int id_is_high; create_cell_t *create_cell; tor_assert(cell); tor_assert(chan); log_debug(LD_OR, "Got a CREATE cell for circ_id %u on channel " U64_FORMAT " (%p)", (unsigned)cell->circ_id, U64_PRINTF_ARG(chan->global_identifier), chan); if (we_are_hibernating()) { log_info(LD_OR, "Received create cell but we're shutting down. Sending back " "destroy."); channel_send_destroy(cell->circ_id, chan, END_CIRC_REASON_HIBERNATING); return; } if (!server_mode(options) || (!public_server_mode(options) && channel_is_outgoing(chan))) { log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL, "Received create cell (type %d) from %s, but we're connected " "to it as a client. " "Sending back a destroy.", (int)cell->command, channel_get_canonical_remote_descr(chan)); channel_send_destroy(cell->circ_id, chan, END_CIRC_REASON_TORPROTOCOL); return; } if (cell->circ_id == 0) { log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL, "Received a create cell (type %d) from %s with zero circID; " " ignoring.", (int)cell->command, channel_get_actual_remote_descr(chan)); return; } /* If the high bit of the circuit ID is not as expected, close the * circ. */ if (chan->wide_circ_ids) id_is_high = cell->circ_id & (1u<<31); else id_is_high = cell->circ_id & (1u<<15); if ((id_is_high && chan->circ_id_type == CIRC_ID_TYPE_HIGHER) || (!id_is_high && chan->circ_id_type == CIRC_ID_TYPE_LOWER)) { log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL, "Received create cell with unexpected circ_id %u. Closing.", (unsigned)cell->circ_id); channel_send_destroy(cell->circ_id, chan, END_CIRC_REASON_TORPROTOCOL); return; } if (circuit_id_in_use_on_channel(cell->circ_id, chan)) { const node_t *node = node_get_by_id(chan->identity_digest); log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL, "Received CREATE cell (circID %u) for known circ. " "Dropping (age %d).", (unsigned)cell->circ_id, (int)(time(NULL) - channel_when_created(chan))); if (node) { char *p = esc_for_log(node_get_platform(node)); log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL, "Details: router %s, platform %s.", node_describe(node), p); tor_free(p); } return; } circ = or_circuit_new(cell->circ_id, chan); circ->base_.purpose = CIRCUIT_PURPOSE_OR; circuit_set_state(TO_CIRCUIT(circ), CIRCUIT_STATE_ONIONSKIN_PENDING); create_cell = tor_malloc_zero(sizeof(create_cell_t)); if (create_cell_parse(create_cell, cell) < 0) { tor_free(create_cell); log_fn(LOG_PROTOCOL_WARN, LD_OR, "Bogus/unrecognized create cell; closing."); circuit_mark_for_close(TO_CIRCUIT(circ), END_CIRC_REASON_TORPROTOCOL); return; } if (create_cell->handshake_type != ONION_HANDSHAKE_TYPE_FAST) { /* hand it off to the cpuworkers, and then return. */ if (connection_or_digest_is_known_relay(chan->identity_digest)) rep_hist_note_circuit_handshake_requested(create_cell->handshake_type); if (assign_onionskin_to_cpuworker(NULL, circ, create_cell) < 0) { log_debug(LD_GENERAL,"Failed to hand off onionskin. Closing."); circuit_mark_for_close(TO_CIRCUIT(circ), END_CIRC_REASON_RESOURCELIMIT); return; } log_debug(LD_OR,"success: handed off onionskin."); } else { /* This is a CREATE_FAST cell; we can handle it immediately without using * a CPU worker. */ uint8_t keys[CPATH_KEY_MATERIAL_LEN]; uint8_t rend_circ_nonce[DIGEST_LEN]; int len; created_cell_t created_cell; /* Make sure we never try to use the OR connection on which we * received this cell to satisfy an EXTEND request, */ channel_mark_client(chan); memset(&created_cell, 0, sizeof(created_cell)); len = onion_skin_server_handshake(ONION_HANDSHAKE_TYPE_FAST, create_cell->onionskin, create_cell->handshake_len, NULL, created_cell.reply, keys, CPATH_KEY_MATERIAL_LEN, rend_circ_nonce); tor_free(create_cell); if (len < 0) { log_warn(LD_OR,"Failed to generate key material. Closing."); circuit_mark_for_close(TO_CIRCUIT(circ), END_CIRC_REASON_INTERNAL); tor_free(create_cell); return; } created_cell.cell_type = CELL_CREATED_FAST; created_cell.handshake_len = len; if (onionskin_answer(circ, &created_cell, (const char *)keys, rend_circ_nonce)<0) { log_warn(LD_OR,"Failed to reply to CREATE_FAST cell. Closing."); circuit_mark_for_close(TO_CIRCUIT(circ), END_CIRC_REASON_INTERNAL); return; } memwipe(keys, 0, sizeof(keys)); } }