From 25c41f4df7079b64ba53184e47edbc012ae96123 Mon Sep 17 00:00:00 2001 From: Martin Willi Date: Sun, 4 Dec 2005 11:46:58 +0000 Subject: [PATCH] - logging cleanup - pid re-replaced with thread_ids, since nptl does not distinguish pids between threads --- Source/charon/config/configuration_manager.c | 1 - Source/charon/daemon.c | 15 +++--- Source/charon/daemon.h | 2 +- Source/charon/encoding/generator.c | 8 +-- Source/charon/encoding/message.c | 15 ++++-- Source/charon/encoding/parser.c | 22 ++++---- Source/charon/network/host.c | 1 - Source/charon/threads/receiver.c | 3 +- Source/charon/threads/scheduler.c | 3 +- Source/charon/threads/sender.c | 3 +- Source/charon/threads/thread_pool.c | 3 +- Source/charon/utils/logger.c | 13 +++-- Source/charon/utils/logger.h | 12 ++--- Source/charon/utils/logger_manager.c | 56 +++++++++++++------- Source/charon/utils/logger_manager.h | 1 + 15 files changed, 87 insertions(+), 71 deletions(-) diff --git a/Source/charon/config/configuration_manager.c b/Source/charon/config/configuration_manager.c index 674828e7b..a5f9499ef 100644 --- a/Source/charon/config/configuration_manager.c +++ b/Source/charon/config/configuration_manager.c @@ -393,7 +393,6 @@ static status_t get_init_config_for_host (private_configuration_manager_t *this, /* could be right one, check my_host for default route*/ if (config_my_host->is_default_route(config_my_host)) { - printf("is default route\n"); *init_config = entry->init_config; status = SUCCESS; break; diff --git a/Source/charon/daemon.c b/Source/charon/daemon.c index be9900757..d015a955d 100644 --- a/Source/charon/daemon.c +++ b/Source/charon/daemon.c @@ -23,7 +23,6 @@ #include #include #include -#include #include "daemon.h" @@ -58,9 +57,9 @@ struct private_daemon_t { sigset_t signal_set; /** - * pid of main-thread + * thread_id of main-thread */ - pid_t main_thread_pid; + pthread_t main_thread_id; /** * main loop @@ -135,7 +134,7 @@ static void kill_daemon(private_daemon_t *this, char *reason) { /* we send SIGTERM, so the daemon can cleanly shut down */ this->logger->log(this->logger, ERROR, "Killing daemon: %s", reason); - if (this->main_thread_pid == getpid()) + if (this->main_thread_id == pthread_self()) { /* initialization failed, terminate daemon */ this->destroy(this); @@ -156,11 +155,11 @@ static void kill_daemon(private_daemon_t *this, char *reason) static void build_test_jobs(private_daemon_t *this) { int i; - for(i = 0; i<1; i++) + for(i = 0; i<100; i++) { initiate_ike_sa_job_t *initiate_job; initiate_job = initiate_ike_sa_job_create("localhost"); - this->public.job_queue->add(this->public.job_queue, (job_t*)initiate_job); + this->public.event_queue->add_relative(this->public.event_queue, (job_t*)initiate_job, i * 5000); } } @@ -179,7 +178,7 @@ static void initialize(private_daemon_t *this) this->public.sender = sender_create(); this->public.receiver = receiver_create(); this->public.scheduler = scheduler_create(); - this->public.prime_pool = prime_pool_create(0); + this->public.prime_pool = prime_pool_create(10); this->public.thread_pool = thread_pool_create(NUMBER_OF_WORKING_THREADS); } @@ -271,7 +270,7 @@ private_daemon_t *daemon_create() this->public.scheduler = NULL; this->public.thread_pool = NULL; - this->main_thread_pid = getpid(); + this->main_thread_id = pthread_self(); /* setup signal handling */ sigemptyset(&(this->signal_set)); diff --git a/Source/charon/daemon.h b/Source/charon/daemon.h index b0591d8bd..3e010de2d 100644 --- a/Source/charon/daemon.h +++ b/Source/charon/daemon.h @@ -72,7 +72,7 @@ * maximum allowed level for ever context, the definiton * of the context may be less verbose. */ -#define DEFAULT_LOGLEVEL FULL +#define DEFAULT_LOGLEVEL CONTROL typedef struct daemon_t daemon_t; diff --git a/Source/charon/encoding/generator.c b/Source/charon/encoding/generator.c index 83dfa062e..cfc96f4b2 100644 --- a/Source/charon/encoding/generator.c +++ b/Source/charon/encoding/generator.c @@ -553,7 +553,7 @@ static void make_space_available (private_generator_t *this, size_t bits) size_t new_buffer_size = old_buffer_size + GENERATOR_DATA_BUFFER_INCREASE_VALUE; size_t out_position_offset = ((this->out_position) - (this->buffer)); - this->logger->log(this->logger, CONTROL|MOST, "increased gen buffer from %d to %d byte", + this->logger->log(this->logger, CONTROL|ALL, "increased gen buffer from %d to %d byte", old_buffer_size, new_buffer_size); /* Reallocate space for new buffer */ @@ -657,7 +657,7 @@ static void generate_payload (private_generator_t *this,payload_t *payload) payload_start = this->out_position; - this->logger->log(this->logger, CONTROL, "generating payload of type %s", + this->logger->log(this->logger, CONTROL|MORE, "generating payload of type %s", mapping_find(payload_type_m,payload_type)); /* each payload has its own encoding rules */ @@ -665,7 +665,7 @@ static void generate_payload (private_generator_t *this,payload_t *payload) for (i = 0; i < rule_count;i++) { - this->logger->log(this->logger, CONTROL|MORE, " generating rule %d %s", + this->logger->log(this->logger, CONTROL|MOST, " generating rule %d %s", i, mapping_find(encoding_type_m,rules[i].type)); switch (rules[i].type) { @@ -928,7 +928,7 @@ static void generate_payload (private_generator_t *this,payload_t *payload) { if (this->attribute_format == FALSE) { - this->logger->log(this->logger, CONTROL|MOST, "attribute value has not fixed size"); + this->logger->log(this->logger, CONTROL|ALL, "attribute value has not fixed size"); /* the attribute value is generated */ this->generate_from_chunk(this,rules[i].offset); } diff --git a/Source/charon/encoding/message.c b/Source/charon/encoding/message.c index 996f8fb87..c46918ed3 100644 --- a/Source/charon/encoding/message.c +++ b/Source/charon/encoding/message.c @@ -656,7 +656,7 @@ static status_t parse_header(private_message_t *this) status_t status; - this->logger->log(this->logger, CONTROL, "parsing Header of message"); + this->logger->log(this->logger, CONTROL|MORE, "parsing Header of message"); this->parser->reset_context(this->parser); status = this->parser->parse_payload(this->parser,HEADER,(payload_t **) &ike_header); @@ -692,8 +692,8 @@ static status_t parse_header(private_message_t *this) this->minor_version = ike_header->get_min_version(ike_header); this->first_payload = ike_header->payload_interface.get_next_type(&(ike_header->payload_interface)); - - this->logger->log(this->logger, CONTROL, "Parsing and verification of header successfully"); + this->logger->log(this->logger, CONTROL, "Parsed a %s %s", mapping_find(exchange_type_m, this->exchange_type), + this->is_request ? "request" : "response"); ike_header->destroy(ike_header); return SUCCESS; @@ -707,14 +707,14 @@ static status_t parse_body(private_message_t *this, crypter_t *crypter, signer_t status_t status = SUCCESS; payload_type_t current_payload_type = this->first_payload; - this->logger->log(this->logger, CONTROL, "Parsing body of message, first payload %s", + this->logger->log(this->logger, CONTROL|MORE, "Parsing body of message, first payload %s", mapping_find(payload_type_m, current_payload_type)); while ((current_payload_type != NO_PAYLOAD)) { payload_t *current_payload; - this->logger->log(this->logger, CONTROL|MORE, "Start parsing payload of type %s", + this->logger->log(this->logger, CONTROL|MOST, "Start parsing payload of type %s", mapping_find(payload_type_m, current_payload_type)); status = this->parser->parse_payload(this->parser,current_payload_type,(payload_t **) ¤t_payload); @@ -751,6 +751,11 @@ static status_t parse_body(private_message_t *this, crypter_t *crypter, signer_t /* get next payload type */ current_payload_type = current_payload->get_next_type(current_payload); } + + this->logger->log(this->logger, CONTROL, "Message a %s %s contains %d payloads", + mapping_find(exchange_type_m, this->exchange_type), + this->is_request ? "request" : "response", + this->payloads->get_count(this->payloads)); status = this->decrypt_and_verify_payloads(this,crypter,signer); if (status != SUCCESS) diff --git a/Source/charon/encoding/parser.c b/Source/charon/encoding/parser.c index aa037ce72..509deaca9 100644 --- a/Source/charon/encoding/parser.c +++ b/Source/charon/encoding/parser.c @@ -238,7 +238,7 @@ static status_t parse_uint4(private_parser_t *this, int rule_number, u_int8_t *o { if (this->byte_pos + sizeof(u_int8_t) > this->input_roof) { - this->logger->log(this->logger, ERROR, " not enough input to parse rule %d %s", + this->logger->log(this->logger, ERROR|MORE, " not enough input to parse rule %d %s", rule_number, mapping_find(encoding_type_m, this->rules[rule_number].type)); return PARSE_ERROR; @@ -284,7 +284,7 @@ static status_t parse_uint8(private_parser_t *this, int rule_number, u_int8_t *o { if (this->byte_pos + sizeof(u_int8_t) > this->input_roof) { - this->logger->log(this->logger, ERROR, " not enough input to parse rule %d %s", + this->logger->log(this->logger, ERROR|MORE, " not enough input to parse rule %d %s", rule_number, mapping_find(encoding_type_m, this->rules[rule_number].type)); return PARSE_ERROR; @@ -315,7 +315,7 @@ static status_t parse_uint15(private_parser_t *this, int rule_number, u_int16_t { if (this->byte_pos + sizeof(u_int16_t) > this->input_roof) { - this->logger->log(this->logger, ERROR, " not enough input to parse rule %d %s", + this->logger->log(this->logger, ERROR|MORE, " not enough input to parse rule %d %s", rule_number, mapping_find(encoding_type_m, this->rules[rule_number].type)); return PARSE_ERROR; @@ -346,7 +346,7 @@ static status_t parse_uint16(private_parser_t *this, int rule_number, u_int16_t { if (this->byte_pos + sizeof(u_int16_t) > this->input_roof) { - this->logger->log(this->logger, ERROR, " not enough input to parse rule %d %s", + this->logger->log(this->logger, ERROR|MORE, " not enough input to parse rule %d %s", rule_number, mapping_find(encoding_type_m, this->rules[rule_number].type)); return PARSE_ERROR; } @@ -375,7 +375,7 @@ static status_t parse_uint32(private_parser_t *this, int rule_number, u_int32_t { if (this->byte_pos + sizeof(u_int32_t) > this->input_roof) { - this->logger->log(this->logger, ERROR, " not enough input to parse rule %d %s", + this->logger->log(this->logger, ERROR|MORE, " not enough input to parse rule %d %s", rule_number, mapping_find(encoding_type_m, this->rules[rule_number].type)); return PARSE_ERROR; } @@ -405,7 +405,7 @@ static status_t parse_uint64(private_parser_t *this, int rule_number, u_int64_t { if (this->byte_pos + sizeof(u_int64_t) > this->input_roof) { - this->logger->log(this->logger, ERROR, " not enough input to parse rule %d %s", + this->logger->log(this->logger, ERROR|MORE, " not enough input to parse rule %d %s", rule_number, mapping_find(encoding_type_m, this->rules[rule_number].type)); return PARSE_ERROR; } @@ -437,7 +437,7 @@ static status_t parse_bytes (private_parser_t *this, int rule_number, u_int8_t * { if (this->byte_pos + bytes > this->input_roof) { - this->logger->log(this->logger, ERROR, " not enough input to parse rule %d %s", + this->logger->log(this->logger, ERROR|MORE, " not enough input to parse rule %d %s", rule_number, mapping_find(encoding_type_m, this->rules[rule_number].type)); return PARSE_ERROR; } @@ -468,7 +468,7 @@ static status_t parse_bit(private_parser_t *this, int rule_number, bool *output_ { if (this->byte_pos + sizeof(u_int8_t) > this->input_roof) { - this->logger->log(this->logger, ERROR, " not enough input to parse rule %d %s", + this->logger->log(this->logger, ERROR|MORE, " not enough input to parse rule %d %s", rule_number, mapping_find(encoding_type_m, this->rules[rule_number].type)); return PARSE_ERROR; } @@ -505,7 +505,7 @@ static status_t parse_list(private_parser_t *this, int rule_number, linked_list_ if (length < 0) { - this->logger->log(this->logger, ERROR, " invalid length for rule %d %s", + this->logger->log(this->logger, ERROR|MORE, " invalid length for rule %d %s", rule_number, mapping_find(encoding_type_m, this->rules[rule_number].type)); return PARSE_ERROR; } @@ -580,7 +580,7 @@ static status_t parse_payload(private_parser_t *this, payload_type_t payload_typ int rule_number; encoding_rule_t *rule; - this->logger->log(this->logger, CONTROL, "parsing %s payload, %d bytes left", + this->logger->log(this->logger, CONTROL|MORE, "parsing %s payload, %d bytes left", mapping_find(payload_type_m, payload_type), this->input_roof-this->byte_pos); @@ -602,7 +602,7 @@ static status_t parse_payload(private_parser_t *this, payload_type_t payload_typ for (rule_number = 0; rule_number < rule_count; rule_number++) { rule = &(this->rules[rule_number]); - this->logger->log(this->logger, CONTROL|MORE, " parsing rule %d %s", + this->logger->log(this->logger, CONTROL|MOST, " parsing rule %d %s", rule_number, mapping_find(encoding_type_m, rule->type)); switch (rule->type) { diff --git a/Source/charon/network/host.c b/Source/charon/network/host.c index 8208586ec..7313aedce 100644 --- a/Source/charon/network/host.c +++ b/Source/charon/network/host.c @@ -85,7 +85,6 @@ static bool is_default_route (private_host_t *this) { static u_int8_t default_route[4] = {0x00,0x00,0x00,0x00}; struct sockaddr_in *sin = (struct sockaddr_in*)&(this->address); - printf("host address: %ul\n", sin->sin_addr.s_addr); if (memcmp(default_route,&(sin->sin_addr.s_addr),4) == 0) { diff --git a/Source/charon/threads/receiver.c b/Source/charon/threads/receiver.c index e02fd89e1..85410d298 100644 --- a/Source/charon/threads/receiver.c +++ b/Source/charon/threads/receiver.c @@ -22,7 +22,6 @@ #include #include -#include #include "receiver.h" @@ -74,7 +73,7 @@ static void receive_packets(private_receiver_t * this) /* cancellation disabled by default */ pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL); - this->logger->log(this->logger, CONTROL, "receiver thread running, pid %d", getpid()); + this->logger->log(this->logger, CONTROL, "receiver thread running, thread_id %u", (int)pthread_self()); while (1) { diff --git a/Source/charon/threads/scheduler.c b/Source/charon/threads/scheduler.c index 50271eb62..e4f9ab308 100644 --- a/Source/charon/threads/scheduler.c +++ b/Source/charon/threads/scheduler.c @@ -22,7 +22,6 @@ #include #include -#include #include "scheduler.h" @@ -73,7 +72,7 @@ static void get_events(private_scheduler_t * this) /* cancellation disabled by default */ pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL); - this->logger->log(this->logger, CONTROL, "scheduler thread running, pid %d", getpid()); + this->logger->log(this->logger, CONTROL, "scheduler thread running, thread_id %u", (int)pthread_self()); for (;;) { diff --git a/Source/charon/threads/sender.c b/Source/charon/threads/sender.c index 7c7180ad8..c47c4e2c0 100644 --- a/Source/charon/threads/sender.c +++ b/Source/charon/threads/sender.c @@ -22,7 +22,6 @@ #include #include -#include #include "sender.h" @@ -74,7 +73,7 @@ static void send_packets(private_sender_t * this) /* cancellation disabled by default */ pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL); - this->logger->log(this->logger, CONTROL, "sender thread running, pid %d", getpid()); + this->logger->log(this->logger, CONTROL, "sender thread running, thread_id %u", (int)pthread_self()); while (1) { diff --git a/Source/charon/threads/thread_pool.c b/Source/charon/threads/thread_pool.c index 26c4d1f29..0146e1c6e 100644 --- a/Source/charon/threads/thread_pool.c +++ b/Source/charon/threads/thread_pool.c @@ -24,7 +24,6 @@ #include #include #include -#include #include "thread_pool.h" @@ -119,7 +118,7 @@ static void process_jobs(private_thread_pool_t *this) /* cancellation disabled by default */ pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL); - this->worker_logger->log(this->worker_logger, CONTROL, "worker thread running, pid: %d", getpid()); + this->worker_logger->log(this->worker_logger, CONTROL, "worker thread running, thread_id: %u", (int)pthread_self()); for (;;) { job_t *job; diff --git a/Source/charon/utils/logger.c b/Source/charon/utils/logger.c index 6f5c51582..d59236cba 100644 --- a/Source/charon/utils/logger.c +++ b/Source/charon/utils/logger.c @@ -26,7 +26,6 @@ #include #include #include -#include #include "logger.h" @@ -63,9 +62,9 @@ struct private_logger_t { FILE *output; /** - * Should a pid be included in the log? + * Should a thread_id be included in the log? */ - bool log_pid; + bool log_thread_id; /** * Applies a prefix to string and stores it in buffer. @@ -119,9 +118,9 @@ static void prepend_prefix(private_logger_t *this, logger_level_t loglevel, char log_details = '0'; } - if (this->log_pid) + if (this->log_thread_id) { - snprintf(buffer, MAX_LOG, "[%c%c] [%s] @%d %s", log_type, log_details, this->name, getpid(), string); + snprintf(buffer, MAX_LOG, "[%c%c] [%s] @%u %s", log_type, log_details, this->name, (int)pthread_self(), string); } else { @@ -294,7 +293,7 @@ static void destroy(private_logger_t *this) /* * Described in header. */ -logger_t *logger_create(char *logger_name, logger_level_t log_level, bool log_pid, FILE * output) +logger_t *logger_create(char *logger_name, logger_level_t log_level, bool log_thread_id, FILE * output) { private_logger_t *this = allocator_alloc_thing(private_logger_t); @@ -314,7 +313,7 @@ logger_t *logger_create(char *logger_name, logger_level_t log_level, bool log_pi /* private variables */ this->level = log_level; - this->log_pid = log_pid; + this->log_thread_id = log_thread_id; this->name = allocator_alloc(strlen(logger_name) + 1); strcpy(this->name,logger_name); diff --git a/Source/charon/utils/logger.h b/Source/charon/utils/logger.h index 7f98b9d6c..ee64a6a1a 100644 --- a/Source/charon/utils/logger.h +++ b/Source/charon/utils/logger.h @@ -110,8 +110,8 @@ struct logger_t { * * @param this logger_t object * @param loglevel or'ed set of loglevels - * @param label a labeling name, logged with the bytes - * @param bytes pointer to the bytes to dump + * @param label a labeling name, logged with the bytes + * @param bytes pointer to the bytes to dump * @param len number of bytes to dump */ void (*log_bytes) (logger_t *this, logger_level_t loglevel, char *label, char *bytes, size_t len); @@ -124,7 +124,7 @@ struct logger_t { * * @param this logger_t object * @param loglevel or'ed set of loglevels - * @param label a labeling name, logged with the bytes + * @param label a labeling name, logged with the bytes * @param chunk pointer to a chunk to log */ void (*log_chunk) (logger_t *this, logger_level_t loglevel, char *label, chunk_t *chunk); @@ -158,13 +158,13 @@ struct logger_t { * * @param logger_name name for the logger_t object * @param log_level or'ed set of log_levels to assign to the new logger_t object - * @param log_pid TRUE if thread id should also be logged - * @param output FILE * if log has to go on a file output, NULL for syslog + * @param log_thread_id TRUE if thread id should also be logged + * @param output FILE * if log has to go on a file output, NULL for syslog * @return logger_t object * * @ingroup utils */ -logger_t *logger_create(char *logger_name, logger_level_t log_level, bool log_pid, FILE * output); +logger_t *logger_create(char *logger_name, logger_level_t log_level, bool log_thread_id, FILE * output); #endif /*LOGGER_H_*/ diff --git a/Source/charon/utils/logger_manager.c b/Source/charon/utils/logger_manager.c index 91f83a7f4..f5ebc7d01 100644 --- a/Source/charon/utils/logger_manager.c +++ b/Source/charon/utils/logger_manager.c @@ -43,6 +43,8 @@ mapping_t logger_context_t_mappings[] = { {DAEMON, "DAEMON"}, {CONFIGURATION_MANAGER, "CONFIG"}, {ENCRYPTION_PAYLOAD, "ENCPLD"}, + {PRIME_POOL, "PRIMEP"}, + {MAPPING_END, NULL}, }; /** @@ -137,40 +139,56 @@ static logger_t *create_logger(private_logger_manager_t *this, logger_context_t /* output to stdout, since we are debugging all days */ output = stdout; + + /* defaults */ + log_thread_ids = FALSE; + logger_level = this->public.get_logger_level(&(this->public),context);; switch(context) { case TESTER: - log_thread_ids = FALSE; output = stdout; - logger_level |= FULL; + break; + case IKE_SA_MANAGER: + log_thread_ids = TRUE; break; case IKE_SA: - logger_level |= FULL; - case IKE_SA_MANAGER: - case WORKER: + log_thread_ids = TRUE; + break; case CONFIGURATION_MANAGER: - logger_level |= ALL; + log_thread_ids = TRUE; + break; case MESSAGE: + log_thread_ids = TRUE; + break; case ENCRYPTION_PAYLOAD: - + log_thread_ids = TRUE; + break; case GENERATOR: - case THREAD_POOL: - case SCHEDULER: - case SENDER: - case RECEIVER: - case SOCKET: - case DAEMON: - logger_level |= CONTROL; + log_thread_ids = TRUE; + break; case PARSER: - log_thread_ids = FALSE; - logger_level |= ERROR; + log_thread_ids = TRUE; + break; + case WORKER: + log_thread_ids = TRUE; + break; + case THREAD_POOL: + break; + case PRIME_POOL: + break; + case SCHEDULER: + break; + case SENDER: + break; + case RECEIVER: + break; + case SOCKET: + break; + case DAEMON: break; } - /* reduce to global definiton of loglevel */ - logger_level &= this->public.get_logger_level(&(this->public),context); - /* logger manager is thread save */ pthread_mutex_lock(&(this->mutex)); if (name != NULL) diff --git a/Source/charon/utils/logger_manager.h b/Source/charon/utils/logger_manager.h index 80a9291fc..7658e4282 100644 --- a/Source/charon/utils/logger_manager.h +++ b/Source/charon/utils/logger_manager.h @@ -50,6 +50,7 @@ enum logger_context_t { DAEMON, CONFIGURATION_MANAGER, ENCRYPTION_PAYLOAD, + PRIME_POOL, }; typedef struct logger_manager_t logger_manager_t;