Macro-fu to get DEBUG events working.

svn:r4539
This commit is contained in:
Nick Mathewson 2005-07-13 05:14:42 +00:00
parent ae44532170
commit cf13b3e4a6
6 changed files with 62 additions and 22 deletions

View File

@ -164,8 +164,6 @@ $Id$
EventCode = "CIRC" / "STREAM" / "ORCONN" / "BW" / "DEBUG" /
"INFO" / "NOTICE" / "WARN" / "ERR" / "NEWDESC" / "ADDRMAP"
[XXX DEBUG doesn't work. -NM]
Any events *not* listed in the SETEVENTS line are turned off; thus, sending
SETEVENTS with an empty body turns off all event reporting.

View File

@ -332,7 +332,7 @@ options_act(void)
* gone. */
close_temp_logs();
add_callback_log(LOG_ERR, LOG_ERR, control_event_logmsg);
adjust_event_log_severity();
control_adjust_event_log_severity();
/* Set up libevent. */
if (!libevent_initialized) {

View File

@ -925,7 +925,7 @@ static void
connection_consider_empty_buckets(connection_t *conn)
{
if (global_read_bucket <= 0) {
log_fn(LOG_DEBUG,"global bucket exhausted. Pausing.");
LOG_FN_CONN(conn, (LOG_DEBUG,"global bucket exhausted. Pausing."));
conn->wants_to_read = 1;
connection_stop_reading(conn);
return;
@ -933,7 +933,7 @@ connection_consider_empty_buckets(connection_t *conn)
if (connection_speaks_cells(conn) &&
conn->state == OR_CONN_STATE_OPEN &&
conn->receiver_bucket <= 0) {
log_fn(LOG_DEBUG,"receiver bucket exhausted. Pausing.");
LOG_FN_CONN(conn, (LOG_DEBUG,"receiver bucket exhausted. Pausing."));
conn->wants_to_read = 1;
connection_stop_reading(conn);
}
@ -986,7 +986,7 @@ connection_bucket_refill(struct timeval *now)
conn->state != OR_CONN_STATE_OPEN ||
conn->receiver_bucket > 0)) {
/* and either a non-cell conn or a cell conn with non-empty bucket */
log_fn(LOG_DEBUG,"waking up conn (fd %d)",conn->s);
LOG_FN_CONN(conn, (LOG_DEBUG,"waking up conn (fd %d)",conn->s));
conn->wants_to_read = 0;
connection_start_reading(conn);
if (conn->wants_to_write == 1) {
@ -1165,8 +1165,9 @@ connection_read_to_buf(connection_t *conn, int *max_to_read)
}
} else {
result = read_to_buf(conn->s, at_most, conn->inbuf,
&conn->inbuf_reached_eof);
CONN_LOG_PROTECT(conn,
result = read_to_buf(conn->s, at_most, conn->inbuf,
&conn->inbuf_reached_eof));
// log_fn(LOG_DEBUG,"read_to_buf returned %d.",read_result);
@ -1328,7 +1329,8 @@ connection_handle_write(connection_t *conn)
*/
}
} else {
result = flush_buf(conn->s, conn->outbuf, &conn->outbuf_flushlen);
CONN_LOG_PROTECT(conn,
result = flush_buf(conn->s, conn->outbuf, &conn->outbuf_flushlen));
if (result < 0) {
if (CONN_IS_EDGE(conn))
connection_edge_end_errno(conn, conn->cpath_layer);
@ -1369,7 +1371,8 @@ _connection_controller_force_write(connection_t *conn)
if (conn->marked_for_close || conn->s < 0)
return;
result = flush_buf(conn->s, conn->outbuf, &conn->outbuf_flushlen);
CONN_LOG_PROTECT(conn,
result = flush_buf(conn->s, conn->outbuf, &conn->outbuf_flushlen));
if (result < 0) {
connection_close_immediate(conn); /* Don't flush; connection is dead. */
connection_mark_for_close(conn);
@ -1395,13 +1398,15 @@ _connection_controller_force_write(connection_t *conn)
void
connection_write_to_buf(const char *string, size_t len, connection_t *conn)
{
int r;
if (!len)
return;
/* if it's marked for close, only allow write if we mean to flush it */
if (conn->marked_for_close && !conn->hold_open_until_flushed)
return;
if (write_to_buf(string, len, conn->outbuf) < 0) {
CONN_LOG_PROTECT(conn, r = write_to_buf(string, len, conn->outbuf));
if (r < 0) {
if (CONN_IS_EDGE(conn)) {
/* if it failed, it means we have our package/delivery windows set
wrong compared to our max outbuf size. close the whole circuit. */

View File

@ -106,6 +106,9 @@ static const char * CONTROL0_COMMANDS[_CONTROL0_CMD_MAX_RECOGNIZED+1] = {
static uint32_t global_event_mask0 = 0;
static uint32_t global_event_mask1 = 0;
/** True iff we have disabled log messages from being sent to the controller */
static int disable_log_messages = 0;
/** Macro: true if any control connection is interested in events of type
* <b>e</b>. */
#define EVENT_IS_INTERESTING0(e) (global_event_mask0 & (1<<(e)))
@ -219,12 +222,12 @@ update_global_event_mask(void)
}
}
adjust_event_log_severity();
control_adjust_event_log_severity();
}
/** DOCDOC */
void
adjust_event_log_severity(void)
control_adjust_event_log_severity(void)
{
int i;
int min_log_event=EVENT_ERR_MSG, max_log_event=EVENT_DEBUG_MSG;
@ -795,7 +798,7 @@ handle_control_setevents(connection_t *conn, uint32_t len, const char *body)
else if (!strcasecmp(ev, "BW"))
event_code = EVENT_BANDWIDTH_USED;
else if (!strcasecmp(ev, "DEBUG"))
continue; /* Don't do debug messages */
event_code = EVENT_DEBUG_MSG;
else if (!strcasecmp(ev, "INFO"))
event_code = EVENT_INFO_MSG;
else if (!strcasecmp(ev, "NOTICE"))
@ -2274,14 +2277,28 @@ control_event_bandwidth_used(uint32_t n_read, uint32_t n_written)
return 0;
}
/** DOCDOC */
void
disable_control_logging(void)
{
++disable_log_messages;
}
/** DOCDOC */
void
enable_control_logging(void)
{
if (--disable_log_messages < 0)
tor_assert(0);
}
/** We got a log message: tell any interested control connections. */
void
control_event_logmsg(int severity, const char *msg)
{
static int sending_logmsg=0;
int oldlog, event;
if (sending_logmsg)
if (disable_log_messages)
return;
oldlog = EVENT_IS_INTERESTING0(EVENT_LOG_OBSOLETE) &&
@ -2293,12 +2310,12 @@ control_event_logmsg(int severity, const char *msg)
if (oldlog || event) {
size_t len = strlen(msg);
sending_logmsg = 1;
disable_log_messages = 1;
if (event)
send_control0_event(event, (uint32_t)(len+1), msg);
if (oldlog)
send_control0_event(EVENT_LOG_OBSOLETE, (uint32_t)(len+1), msg);
sending_logmsg = 0;
disable_log_messages = 0;
}
event = log_severity_to_event(severity);
@ -2313,13 +2330,16 @@ control_event_logmsg(int severity, const char *msg)
*cp = ' ';
}
switch (severity) {
case LOG_DEBUG: s = "DEBUG"; break;
case LOG_INFO: s = "INFO"; break;
case LOG_NOTICE: s = "NOTICE"; break;
case LOG_WARN: s = "WARN"; break;
case LOG_ERR: s = "ERR"; break;
default: s = "UnknownLogSeverity"; break;
}
disable_log_messages = 1;
send_control1_event(event, "650 %s %s\r\n", s, b?b:msg);
disable_log_messages = 0;
tor_free(b);
}
}

View File

@ -364,7 +364,7 @@ conn_read_callback(int fd, short event, void *_conn)
{
connection_t *conn = _conn;
log_fn(LOG_DEBUG,"socket %d wants to read.",conn->s);
LOG_FN_CONN(conn, (LOG_DEBUG,"socket %d wants to read.",conn->s));
assert_connection_ok(conn, time(NULL));
@ -393,7 +393,7 @@ conn_write_callback(int fd, short events, void *_conn)
{
connection_t *conn = _conn;
log_fn(LOG_DEBUG,"socket %d wants to write.",conn->s);
LOG_FN_CONN(conn, (LOG_DEBUG,"socket %d wants to write.",conn->s));
assert_connection_ok(conn, time(NULL));
@ -454,7 +454,8 @@ conn_close_if_marked(int i)
}
if (retval >= 0 &&
conn->hold_open_until_flushed && connection_wants_to_flush(conn)) {
log_fn(LOG_INFO,"Holding conn (fd %d) open for more flushing.",conn->s);
LOG_FN_CONN(conn,
(LOG_INFO,"Holding conn (fd %d) open for more flushing.",conn->s));
/* XXX should we reset timestamp_lastwritten here? */
return 0;
}

View File

@ -1504,7 +1504,23 @@ typedef enum or_conn_status_event_t {
OR_CONN_EVENT_CLOSED = 3,
} or_conn_status_event_t;
void adjust_event_log_severity(void);
void control_adjust_event_log_severity(void);
void disable_control_logging(void);
void enable_control_logging(void);
#define CONN_LOG_PROTECT(conn, stmt) \
do { \
int _log_conn_is_control = (conn && conn->type == CONN_TYPE_CONTROL); \
if (_log_conn_is_control) \
disable_control_logging(); \
do {stmt;} while(0); \
if (_log_conn_is_control) \
enable_control_logging(); \
} while (0)
#define LOG_FN_CONN(conn, args) \
CONN_LOG_PROTECT(conn, log_fn args)
int connection_control_finished_flushing(connection_t *conn);
int connection_control_reached_eof(connection_t *conn);
int connection_control_process_inbuf(connection_t *conn);