From 5346c8946053a473af960f34c74d36e03a06b1e3 Mon Sep 17 00:00:00 2001 From: Martin Willi Date: Wed, 7 Dec 2005 11:49:54 +0000 Subject: [PATCH] - logging cleanup in states --- Source/charon/encoding/message.c | 2 +- Source/charon/sa/states/ike_auth_requested.c | 5 +- .../charon/sa/states/ike_sa_init_requested.c | 255 +++++++++--------- .../charon/sa/states/ike_sa_init_requested.h | 2 + .../charon/sa/states/ike_sa_init_responded.c | 2 +- Source/charon/sa/states/initiator_init.c | 23 +- Source/charon/sa/states/responder_init.c | 165 +++++------- 7 files changed, 218 insertions(+), 236 deletions(-) diff --git a/Source/charon/encoding/message.c b/Source/charon/encoding/message.c index cb4db5ba9..b67f06dd7 100644 --- a/Source/charon/encoding/message.c +++ b/Source/charon/encoding/message.c @@ -787,7 +787,7 @@ static status_t parse_body(private_message_t *this, crypter_t *crypter, signer_t this->logger->log(this->logger, ERROR, "Verification of message failed"); } - this->logger->log(this->logger, CONTROL, "Message a %s %s contains %d payloads", + this->logger->log(this->logger, CONTROL, "Message %s %s contains %d payloads", mapping_find(exchange_type_m, this->exchange_type), this->is_request ? "request" : "response", this->payloads->get_count(this->payloads)); diff --git a/Source/charon/sa/states/ike_auth_requested.c b/Source/charon/sa/states/ike_auth_requested.c index 199a062d3..ddcff4c6a 100644 --- a/Source/charon/sa/states/ike_auth_requested.c +++ b/Source/charon/sa/states/ike_auth_requested.c @@ -281,7 +281,7 @@ static status_t process_message(private_ike_auth_requested_t *this, message_t *i this->ike_sa->set_new_state(this->ike_sa, (state_t*)ike_sa_established_create(this->ike_sa)); this->ike_sa->create_delete_established_ike_sa_job(this->ike_sa,this->sa_config->get_ike_sa_lifetime(this->sa_config)); this->public.state_interface.destroy(&(this->public.state_interface)); - + my_host = this->ike_sa->get_my_host(this->ike_sa); other_host = this->ike_sa->get_other_host(this->ike_sa); this->logger->log(this->logger, AUDIT, "IKE_SA established between %s - %s", @@ -478,7 +478,8 @@ static status_t process_notify_payload(private_ike_auth_requested_t *this, notif } else { - this->logger->log(this->logger, AUDIT, "IKE_AUTH reply contained an unknown notify (%d), ignored.", notify_message_type); + this->logger->log(this->logger, CONTROL, "IKE_AUTH reply contained an unknown notify (%d), ignored.", + notify_message_type); return SUCCESS; } } diff --git a/Source/charon/sa/states/ike_sa_init_requested.c b/Source/charon/sa/states/ike_sa_init_requested.c index f86170ac8..c24ff5bb6 100644 --- a/Source/charon/sa/states/ike_sa_init_requested.c +++ b/Source/charon/sa/states/ike_sa_init_requested.c @@ -178,6 +178,14 @@ struct private_ike_sa_init_requested_t { */ status_t (*build_tsr_payload) (private_ike_sa_init_requested_t *this, message_t *response); + /** + * Process a notify payload and react. + * + * @param this calling object + * @param notify_payload notify_payload to handle + */ + status_t (*process_notify_payload) (private_ike_sa_init_requested_t *this, notify_payload_t *notify_payload); + /** * Destroy function called internally of this class after state change to * state IKE_AUTH_REQUESTED succeeded. @@ -198,10 +206,10 @@ static status_t process_message(private_ike_sa_init_requested_t *this, message_t { ike_auth_requested_t *next_state; chunk_t ike_sa_init_reply_data; - nonce_payload_t *nonce_payload; - sa_payload_t *sa_payload; - ke_payload_t *ke_payload; - id_payload_t *id_payload; + sa_payload_t *sa_payload = NULL; + ke_payload_t *ke_payload = NULL; + id_payload_t *id_payload = NULL; + nonce_payload_t *nonce_payload = NULL; u_int64_t responder_spi; ike_sa_id_t *ike_sa_id; iterator_t *payloads; @@ -226,7 +234,7 @@ static status_t process_message(private_ike_sa_init_requested_t *this, message_t if (ike_sa_init_reply->get_request(ike_sa_init_reply)) { - this->logger->log(this->logger, ERROR | LEVEL1, "Only responses of type IKE_SA_INIT supported in state ike_sa_init_requested"); + this->logger->log(this->logger, ERROR | LEVEL1, "IKE_SA_INIT requests not allowed state ike_sa_init_responded"); return FAILED; } @@ -234,16 +242,15 @@ static status_t process_message(private_ike_sa_init_requested_t *this, message_t status = ike_sa_init_reply->parse_body(ike_sa_init_reply, NULL, NULL); if (status != SUCCESS) { - this->logger->log(this->logger, ERROR | LEVEL1, "Parsing of body returned error: %s",mapping_find(status_m,status)); + this->logger->log(this->logger, ERROR | LEVEL1, "IKE_SA_INIT reply parsing faild. Ignoring message"); return status; } - /* because I am original initiator i have to update the responder SPI to the new one */ + /* because we are original initiator we have to update the responder SPI to the new one */ responder_spi = ike_sa_init_reply->get_responder_spi(ike_sa_init_reply); - if (responder_spi == 0) { - this->logger->log(this->logger, ERROR | LEVEL1, "Responder SPI still zero"); + this->logger->log(this->logger, ERROR | LEVEL1, "IKE_SA_INIT reply contained a SPI of zero"); return FAILED; } ike_sa_id = this->ike_sa->public.get_id(&(this->ike_sa->public)); @@ -259,91 +266,8 @@ static status_t process_message(private_ike_sa_init_requested_t *this, message_t payload_t *payload; payloads->current(payloads, (void**)&payload); - this->logger->log(this->logger, CONTROL|LEVEL1, "Processing payload %s", mapping_find(payload_type_m, payload->get_type(payload))); switch (payload->get_type(payload)) { - case NOTIFY: - { - notify_payload_t *notify_payload = (notify_payload_t *) payload; - - - this->logger->log(this->logger, CONTROL|LEVEL1, "Process notify type %s for protocol %s", - mapping_find(notify_message_type_m, notify_payload->get_notify_message_type(notify_payload)), - mapping_find(protocol_id_m, notify_payload->get_protocol_id(notify_payload))); - - if (notify_payload->get_protocol_id(notify_payload) != IKE) - { - this->logger->log(this->logger, ERROR | LEVEL1, "Notify reply not for IKE protocol."); - payloads->destroy(payloads); - return FAILED; - } - switch (notify_payload->get_notify_message_type(notify_payload)) - { - case NO_PROPOSAL_CHOSEN: - { - this->logger->log(this->logger, ERROR, "Peer didn't choose a proposal!"); - payloads->destroy(payloads); - return DELETE_ME; - } - case INVALID_MAJOR_VERSION: - { - this->logger->log(this->logger, ERROR, "Peer doesn't support IKEv2!"); - payloads->destroy(payloads); - return DELETE_ME; - } - case INVALID_KE_PAYLOAD: - { - initiator_init_t *initiator_init_state; - u_int16_t new_dh_group_priority; - - this->logger->log(this->logger, ERROR, "Selected DH group is not the one in the proposal selected by the responder!"); - payloads->destroy(payloads); - /* Going to change state back to initiator_init_t */ - this->logger->log(this->logger, CONTROL|LEVEL2, "Create next state object"); - initiator_init_state = initiator_init_create(this->ike_sa); - - /* buffer of sent and received messages has to get reseted */ - this->ike_sa->reset_message_buffers(this->ike_sa); - - /* state can now be changed */ - this->ike_sa->set_new_state(this->ike_sa,(state_t *) initiator_init_state); - - /* state has NOW changed :-) */ - this->logger->log(this->logger, CONTROL|LEVEL1, "Changed state of IKE_SA from %s to %s", mapping_find(ike_sa_state_m,INITIATOR_INIT),mapping_find(ike_sa_state_m,IKE_SA_INIT_REQUESTED) ); - - this->logger->log(this->logger, CONTROL|LEVEL2, "Destroy old sate object"); - this->logger->log(this->logger, CONTROL|LEVEL2, "Going to retry initialization of connection"); - new_dh_group_priority = this->dh_group_priority + 1; - - this->public.state_interface.destroy(&(this->public.state_interface)); - return (initiator_init_state->retry_initiate_connection (initiator_init_state,new_dh_group_priority)); - } - default: - { - /* - * - In case of unknown error: IKE_SA gets destroyed. - * - In case of unknown status: logging - * - */ - notify_message_type_t notify_message_type = notify_payload->get_notify_message_type(notify_payload); - if (notify_message_type < 16383) - { - this->logger->log(this->logger, ERROR, "Notify error type %d not recognized in state IKE_SA_INIT_REQUESTED.", - notify_message_type); - payloads->destroy(payloads); - return DELETE_ME; - - } - else - { - this->logger->log(this->logger, ERROR, "Notify status type %d not handled in state IKE_SA_INIT_REQUESTED.", - notify_message_type); - break; - } - } - } - - } case SECURITY_ASSOCIATION: { sa_payload = (sa_payload_t*)payload; @@ -359,9 +283,21 @@ static status_t process_message(private_ike_sa_init_requested_t *this, message_t nonce_payload = (nonce_payload_t*)payload; break; } + case NOTIFY: + { + notify_payload_t *notify_payload = (notify_payload_t *) payload; + + status = this->process_notify_payload(this, notify_payload); + if (status != SUCCESS) + { + payloads->destroy(payloads); + return status; + } + } default: { - this->logger->log(this->logger, ERROR, "Payload with ID %d not handled in state IKE_SA_INIT_REQUESTED", payload->get_type(payload)); + this->logger->log(this->logger, ERROR|LEVEL1, "Ignoring payload %s (%d)", + mapping_find(payload_type_m, payload->get_type(payload)), payload->get_type(payload)); break; } @@ -370,6 +306,12 @@ static status_t process_message(private_ike_sa_init_requested_t *this, message_t } payloads->destroy(payloads); + if (!(nonce_payload && sa_payload && ke_payload)) + { + this->logger->log(this->logger, AUDIT, "IKE_SA_INIT reply did not contain all required payloads. Deleting IKE_SA"); + return DELETE_ME; + } + status = this->process_nonce_payload (this,nonce_payload); if (status != SUCCESS) { @@ -388,42 +330,33 @@ static status_t process_message(private_ike_sa_init_requested_t *this, message_t return status; } - this->logger->log(this->logger, CONTROL|LEVEL2, "Going to build empty message"); + /* build empty message */ this->ike_sa->build_message(this->ike_sa, IKE_AUTH, TRUE, &request); - /* build ID payload */ status = this->build_id_payload(this, &id_payload,request); if (status != SUCCESS) { request->destroy(request); return status; } - - /* build AUTH payload */ status = this->build_auth_payload(this,(id_payload_t *) id_payload, request); if (status != SUCCESS) { request->destroy(request); return status; } - - /* build SA payload */ status = this->build_sa_payload(this, request); if (status != SUCCESS) { request->destroy(request); return status; } - - /* build TSi payload */ status = this->build_tsi_payload(this, request); if (status != SUCCESS) { request->destroy(request); return status; } - - /* build TSr payload */ status = this->build_tsr_payload(this, request); if (status != SUCCESS) { @@ -435,7 +368,7 @@ static status_t process_message(private_ike_sa_init_requested_t *this, message_t status = this->ike_sa->send_request(this->ike_sa, request); if (status != SUCCESS) { - this->logger->log(this->logger, ERROR, "Could not send request message"); + this->logger->log(this->logger, AUDIT, "Unable to send IKE_AUTH request. Deleting IKE_SA"); request->destroy(request); return DELETE_ME; } @@ -445,16 +378,9 @@ static status_t process_message(private_ike_sa_init_requested_t *this, message_t ike_sa_init_reply_data = ike_sa_init_reply->get_packet_data(ike_sa_init_reply); /* state can now be changed */ - this->logger->log(this->logger, CONTROL|LEVEL2, "Create next state object"); next_state = ike_auth_requested_create(this->ike_sa,this->sent_nonce,this->received_nonce,ike_sa_init_reply_data); - - /* state can now be changed */ this->ike_sa->set_new_state(this->ike_sa,(state_t *) next_state); - /* state has NOW changed :-) */ - this->logger->log(this->logger, CONTROL|LEVEL1, "Changed state of IKE_SA from %s to %s", mapping_find(ike_sa_state_m,IKE_SA_INIT_REQUESTED),mapping_find(ike_sa_state_m,IKE_AUTH_REQUESTED) ); - - this->logger->log(this->logger, CONTROL|LEVEL2, "Destroy old sate object"); this->destroy_after_state_change(this); return SUCCESS; } @@ -488,13 +414,13 @@ status_t process_sa_payload (private_ike_sa_init_requested_t *this, sa_payload_t status = sa_payload->get_ike_proposals (sa_payload, &ike_proposals,&proposal_count); if (status != SUCCESS) { - this->logger->log(this->logger, ERROR | LEVEL1, "SA payload does not contain IKE proposals"); + this->logger->log(this->logger, AUDIT, "IKE_SA_INIT response did not contain any proposals. Deleting IKE_SA"); return DELETE_ME; } /* the peer has to select only one proposal */ if (proposal_count != 1) { - this->logger->log(this->logger, ERROR | LEVEL1, "More then 1 proposal (%d) selected!",proposal_count); + this->logger->log(this->logger, AUDIT, "IKE_SA_INIT response contained more than one proposal. Deleting IKE_SA"); allocator_free(ike_proposals); return DELETE_ME; } @@ -505,14 +431,14 @@ status_t process_sa_payload (private_ike_sa_init_requested_t *this, sa_payload_t allocator_free(ike_proposals); if (status != SUCCESS) { - this->logger->log(this->logger, ERROR | LEVEL1, "Selected proposal not a suggested one! Peer is trying to trick me!"); + this->logger->log(this->logger, AUDIT, "IKE_SA_INIT response contained selected proposal we did not offer. Deleting IKE_SA"); return DELETE_ME; } status = this->ike_sa->create_transforms_from_proposal(this->ike_sa,&selected_proposal); if (status != SUCCESS) { - this->logger->log(this->logger, ERROR | LEVEL1, "Transform objects could not be created from selected proposal"); + this->logger->log(this->logger, AUDIT, "Transform objects could not be created from selected proposal. Deleting IKE_SA"); return DELETE_ME; } return SUCCESS; @@ -580,6 +506,7 @@ static status_t build_auth_payload (private_ike_sa_init_requested_t *this, id_pa if (status != SUCCESS) { + this->logger->log(this->logger, AUDIT, "Could not generate AUTH data for IKE_AUTH request. Deleting IKE_SA"); return DELETE_ME; } @@ -671,6 +598,83 @@ static status_t build_tsr_payload (private_ike_sa_init_requested_t *this, messag return SUCCESS; } +/** + * Implementation of private_ike_sa_init_requested_t.process_notify_payload. + */ +static status_t process_notify_payload(private_ike_sa_init_requested_t *this, notify_payload_t *notify_payload) +{ + notify_message_type_t notify_message_type = notify_payload->get_notify_message_type(notify_payload); + + this->logger->log(this->logger, CONTROL|LEVEL1, "Process notify type %s for protocol %s", + mapping_find(notify_message_type_m, notify_message_type), + mapping_find(protocol_id_m, notify_payload->get_protocol_id(notify_payload))); + + if (notify_payload->get_protocol_id(notify_payload) != IKE) + { + this->logger->log(this->logger, ERROR | LEVEL1, "Notify reply not for IKE protocol."); + return FAILED; + } + switch (notify_message_type) + { + case NO_PROPOSAL_CHOSEN: + { + this->logger->log(this->logger, AUDIT, "IKE_SA_INIT response contained a NO_PROPOSAL_CHOSEN notify. Deleting IKE_SA"); + return DELETE_ME; + } + case INVALID_MAJOR_VERSION: + { + this->logger->log(this->logger, AUDIT, "IKE_SA_INIT response contained a INVALID_MAJOR_VERSION notify. Deleting IKE_SA"); + return DELETE_ME; + } + case INVALID_KE_PAYLOAD: + { + initiator_init_t *initiator_init_state; + u_int16_t new_dh_group_priority; + + this->logger->log(this->logger, ERROR|LEVEL1, "Selected DH group is not the one in the proposal selected by the responder!"); + /* Going to change state back to initiator_init_t */ + this->logger->log(this->logger, CONTROL|LEVEL2, "Create next state object"); + initiator_init_state = initiator_init_create(this->ike_sa); + + /* buffer of sent and received messages has to get reseted */ + this->ike_sa->reset_message_buffers(this->ike_sa); + + /* state can now be changed */ + this->ike_sa->set_new_state(this->ike_sa,(state_t *) initiator_init_state); + + /* state has NOW changed :-) */ + this->logger->log(this->logger, CONTROL|LEVEL1, "Changed state of IKE_SA from %s to %s", + mapping_find(ike_sa_state_m,INITIATOR_INIT), mapping_find(ike_sa_state_m,IKE_SA_INIT_REQUESTED)); + + this->logger->log(this->logger, CONTROL|LEVEL2, "Destroy old sate object"); + this->logger->log(this->logger, CONTROL|LEVEL2, "Going to retry initialization of connection"); + new_dh_group_priority = this->dh_group_priority + 1; + + this->public.state_interface.destroy(&(this->public.state_interface)); + return (initiator_init_state->retry_initiate_connection (initiator_init_state,new_dh_group_priority)); + } + default: + { + /* + * - In case of unknown error: IKE_SA gets destroyed. + * - In case of unknown status: logging + */ + if (notify_message_type < 16383) + { + this->logger->log(this->logger, AUDIT, "IKE_SA_INIT reply contained an unknown notify error (%d). Deleting IKE_SA", + notify_message_type); + return DELETE_ME; + } + else + { + this->logger->log(this->logger, CONTROL, "IKE_SA_INIT reply contained an unknown notify (%d), ignored.", + notify_message_type); + return SUCCESS; + } + } + } +} + /** * Implementation of state_t.get_state. @@ -685,13 +689,13 @@ static ike_sa_state_t get_state(private_ike_sa_init_requested_t *this) */ static void destroy_after_state_change (private_ike_sa_init_requested_t *this) { - this->logger->log(this->logger, CONTROL | LEVEL1, "Going to destroy state of type ike_sa_init_requested_t after state change."); + this->logger->log(this->logger, CONTROL | LEVEL3, "Going to destroy state of type ike_sa_init_requested_t after state change."); - this->logger->log(this->logger, CONTROL | LEVEL2, "Destroy diffie hellman object"); + this->logger->log(this->logger, CONTROL | LEVEL3, "Destroy diffie hellman object"); this->diffie_hellman->destroy(this->diffie_hellman); - this->logger->log(this->logger, CONTROL | LEVEL2, "Destroy ike_sa_init_request_data"); + this->logger->log(this->logger, CONTROL | LEVEL3, "Destroy ike_sa_init_request_data"); allocator_free_chunk(&(this->ike_sa_init_request_data)); - this->logger->log(this->logger, CONTROL | LEVEL2, "Destroy object itself"); + this->logger->log(this->logger, CONTROL | LEVEL3, "Destroy object itself"); allocator_free(this); } @@ -700,17 +704,17 @@ static void destroy_after_state_change (private_ike_sa_init_requested_t *this) */ static void destroy(private_ike_sa_init_requested_t *this) { - this->logger->log(this->logger, CONTROL | LEVEL1, "Going to destroy state of type ike_sa_init_requested_t"); + this->logger->log(this->logger, CONTROL | LEVEL3, "Going to destroy state of type ike_sa_init_requested_t"); - this->logger->log(this->logger, CONTROL | LEVEL2, "Destroy diffie hellman object"); + this->logger->log(this->logger, CONTROL | LEVEL3, "Destroy diffie hellman object"); this->diffie_hellman->destroy(this->diffie_hellman); - this->logger->log(this->logger, CONTROL | LEVEL2, "Destroy sent nonce"); + this->logger->log(this->logger, CONTROL | LEVEL3, "Destroy sent nonce"); allocator_free(this->sent_nonce.ptr); - this->logger->log(this->logger, CONTROL | LEVEL2, "Destroy received nonce"); + this->logger->log(this->logger, CONTROL | LEVEL3, "Destroy received nonce"); allocator_free(this->received_nonce.ptr); - this->logger->log(this->logger, CONTROL | LEVEL2, "Destroy ike_sa_init_request_data"); + this->logger->log(this->logger, CONTROL | LEVEL3, "Destroy ike_sa_init_request_data"); allocator_free_chunk(&(this->ike_sa_init_request_data)); - this->logger->log(this->logger, CONTROL | LEVEL2, "Destroy object itself"); + this->logger->log(this->logger, CONTROL | LEVEL3, "Destroy object itself"); allocator_free(this); } @@ -736,6 +740,7 @@ ike_sa_init_requested_t *ike_sa_init_requested_create(protected_ike_sa_t *ike_sa this->build_tsr_payload = build_tsr_payload; this->build_id_payload = build_id_payload; this->build_sa_payload = build_sa_payload; + this->process_notify_payload = process_notify_payload; /* private data */ this->ike_sa = ike_sa; diff --git a/Source/charon/sa/states/ike_sa_init_requested.h b/Source/charon/sa/states/ike_sa_init_requested.h index b2456c94c..7d4df6ba8 100644 --- a/Source/charon/sa/states/ike_sa_init_requested.h +++ b/Source/charon/sa/states/ike_sa_init_requested.h @@ -38,6 +38,8 @@ typedef struct ike_sa_init_requested_t ike_sa_init_requested_t; * @b Constructors: * - ike_sa_init_requested_create() * + * @todo Include valid child sa SPIs in proposal + * * @ingroup states */ struct ike_sa_init_requested_t { diff --git a/Source/charon/sa/states/ike_sa_init_responded.c b/Source/charon/sa/states/ike_sa_init_responded.c index b3680da05..9e4efaf21 100644 --- a/Source/charon/sa/states/ike_sa_init_responded.c +++ b/Source/charon/sa/states/ike_sa_init_responded.c @@ -252,7 +252,7 @@ static status_t process_message(private_ike_sa_init_responded_t *this, message_t } default: { - this->logger->log(this->logger, ERROR|LEVEL1, "Ignoring Payload %s (%d)", + this->logger->log(this->logger, ERROR|LEVEL1, "Ignoring payload %s (%d)", mapping_find(payload_type_m, payload->get_type(payload)), payload->get_type(payload)); break; } diff --git a/Source/charon/sa/states/initiator_init.c b/Source/charon/sa/states/initiator_init.c index ae23df9f3..6ab698f89 100644 --- a/Source/charon/sa/states/initiator_init.c +++ b/Source/charon/sa/states/initiator_init.c @@ -154,7 +154,8 @@ static status_t initiate_connection (private_initiator_init_t *this, char *name) this->dh_group_number = init_config->get_dh_group_number(init_config,this->dh_group_priority); if (this->dh_group_number == MODP_UNDEFINED) { - this->logger->log(this->logger, ERROR | LEVEL1, "Diffie hellman group could not be retrieved with priority %d", this->dh_group_priority); + this->logger->log(this->logger, AUDIT, "Could not find a matching diffie hellman group after %d. try. Aborting.", + this->dh_group_priority); return DELETE_ME; } @@ -185,7 +186,8 @@ status_t retry_initiate_connection (private_initiator_init_t *this, int dh_group this->dh_group_number = init_config->get_dh_group_number(init_config,dh_group_priority); if (this->dh_group_number == MODP_UNDEFINED) { - this->logger->log(this->logger, ERROR | LEVEL1, "Diffie hellman group could not be retrieved with priority %d", dh_group_priority); + this->logger->log(this->logger, AUDIT, "Could not find a matching diffie hellman group after %d. try. Aborting.", + this->dh_group_priority); return DELETE_ME; } @@ -209,7 +211,7 @@ status_t retry_initiate_connection (private_initiator_init_t *this, int dh_group status = this->ike_sa->send_request(this->ike_sa, message); if (status != SUCCESS) { - this->logger->log(this->logger, ERROR, "Could not send request message"); + this->logger->log(this->logger, AUDIT, "Unable to initiate connection, could not send message. Aborting"); message->destroy(message); return DELETE_ME; } @@ -221,12 +223,7 @@ status_t retry_initiate_connection (private_initiator_init_t *this, int dh_group /* state can now be changed */ this->logger->log(this->logger, CONTROL|LEVEL2, "Create next state object"); next_state = ike_sa_init_requested_create(this->ike_sa, this->dh_group_priority, this->diffie_hellman, this->sent_nonce,ike_sa_init_request_data); - - /* state can now be changed */ this->ike_sa->set_new_state(this->ike_sa,(state_t *) next_state); - - /* state has NOW changed :-) */ - this->logger->log(this->logger, CONTROL|LEVEL1, "Changed state of IKE_SA from %s to %s", mapping_find(ike_sa_state_m,INITIATOR_INIT),mapping_find(ike_sa_state_m,IKE_SA_INIT_REQUESTED) ); this->logger->log(this->logger, CONTROL|LEVEL2, "Destroy old sate object"); this->destroy_after_state_change(this); @@ -309,7 +306,7 @@ static void build_nonce_payload(private_initiator_init_t *this, message_t *reque */ static status_t process_message(private_initiator_init_t *this, message_t *message) { - this->logger->log(this->logger, ERROR|LEVEL1, "In state INITIATOR_INIT no message is processed"); + this->logger->log(this->logger, ERROR, "In state INITIATOR_INIT no message is processed"); return FAILED; } @@ -326,17 +323,17 @@ static ike_sa_state_t get_state(private_initiator_init_t *this) */ static void destroy(private_initiator_init_t *this) { - this->logger->log(this->logger, CONTROL | LEVEL1, "Going to destroy initiator_init_t state object"); + this->logger->log(this->logger, CONTROL | LEVEL3, "Going to destroy initiator_init_t state object"); /* destroy diffie hellman object */ if (this->diffie_hellman != NULL) { - this->logger->log(this->logger, CONTROL | LEVEL2, "Destroy diffie_hellman_t object"); + this->logger->log(this->logger, CONTROL | LEVEL3, "Destroy diffie_hellman_t object"); this->diffie_hellman->destroy(this->diffie_hellman); } if (this->sent_nonce.ptr != NULL) { - this->logger->log(this->logger, CONTROL | LEVEL2, "Free memory of sent nonce"); + this->logger->log(this->logger, CONTROL | LEVEL3, "Free memory of sent nonce"); allocator_free(this->sent_nonce.ptr); } allocator_free(this); @@ -347,7 +344,7 @@ static void destroy(private_initiator_init_t *this) */ static void destroy_after_state_change (private_initiator_init_t *this) { - this->logger->log(this->logger, CONTROL | LEVEL1, "Going to destroy initiator_init_t state object"); + this->logger->log(this->logger, CONTROL | LEVEL3, "Going to destroy initiator_init_t state object"); allocator_free(this); } diff --git a/Source/charon/sa/states/responder_init.c b/Source/charon/sa/states/responder_init.c index 940a87aa7..a54b486e5 100644 --- a/Source/charon/sa/states/responder_init.c +++ b/Source/charon/sa/states/responder_init.c @@ -120,6 +120,14 @@ struct private_responder_init_t { */ status_t (*build_nonce_payload) (private_responder_init_t *this,nonce_payload_t *nonce_request, message_t *response); + /** + * Sends a IKE_SA_INIT reply containing a notify payload. + * + * @param this calling object + * @param notify_payload notify_payload to process + */ + status_t (*process_notify_payload) (private_responder_init_t *this, notify_payload_t *notify_payload); + /** * Destroy function called internally of this class after change * to state IKE_SA_INIT_RESPONDED succeeded. @@ -129,15 +137,6 @@ struct private_responder_init_t { * @param this calling object */ void (*destroy_after_state_change) (private_responder_init_t *this); - - /** - * Sends a IKE_SA_INIT reply containing a notify payload. - * - * @param this calling object - * @param type type of notify message - * @param data data of notify message - */ - void (*send_notify_reply) (private_responder_init_t *this,notify_message_type_t type, chunk_t data); }; @@ -149,11 +148,11 @@ static status_t process_message(private_responder_init_t *this, message_t *messa ike_sa_init_responded_t *next_state; chunk_t ike_sa_init_response_data; chunk_t ike_sa_init_request_data; - nonce_payload_t *nonce_request; + sa_payload_t *sa_request = NULL; + ke_payload_t *ke_request = NULL; + nonce_payload_t *nonce_request = NULL; host_t *source, *destination; init_config_t *init_config; - sa_payload_t *sa_request; - ke_payload_t *ke_request; chunk_t shared_secret; iterator_t *payloads; message_t *response; @@ -166,7 +165,7 @@ static status_t process_message(private_responder_init_t *this, message_t *messa } if (!message->get_request(message)) { - this->logger->log(this->logger, ERROR | LEVEL1, "Only requests of type IKE_SA_INIT supported in state responder_init"); + this->logger->log(this->logger, ERROR | LEVEL1, "IKE_SA_INIT responses not allowed state ike_sa_init_responded"); return DELETE_ME; } @@ -178,8 +177,8 @@ static status_t process_message(private_responder_init_t *this, message_t *messa if (status != SUCCESS) { /* no configuration matches given host */ - this->logger->log(this->logger, ERROR | LEVEL1, "No INIT configuration found for given remote and local hosts"); - this->send_notify_reply(this,NO_PROPOSAL_CHOSEN,CHUNK_INITIALIZER); + this->logger->log(this->logger, AUDIT, "IKE_SA_INIT request does not match any available configuration. Deleting IKE_SA"); + this->ike_sa->send_notify(this->ike_sa, IKE_SA_INIT, NO_PROPOSAL_CHOSEN, CHUNK_INITIALIZER); return DELETE_ME; } this->ike_sa->set_init_config(this->ike_sa,init_config); @@ -193,15 +192,13 @@ static status_t process_message(private_responder_init_t *this, message_t *messa { if (status == NOT_SUPPORTED) { - this->logger->log(this->logger, ERROR | LEVEL1, "Message contains unsupported payload with critical flag set"); - /** - * TODO send unsupported type. - */ - this->send_notify_reply(this,UNSUPPORTED_CRITICAL_PAYLOAD,CHUNK_INITIALIZER); + this->logger->log(this->logger, AUDIT, "IKE_SA_INIT request contains unsupported payload with critical flag set. " + "Deleting IKE_SA"); + this->ike_sa->send_notify(this->ike_sa, IKE_SA_INIT, UNSUPPORTED_CRITICAL_PAYLOAD, CHUNK_INITIALIZER); } else { - this->logger->log(this->logger, ERROR | LEVEL1, "Could not parse body of request message"); + this->logger->log(this->logger, AUDIT, "Unable to parse IKE_SA_INIT request. Deleting IKE_SA"); } return DELETE_ME; } @@ -233,36 +230,30 @@ static status_t process_message(private_responder_init_t *this, message_t *messa case NOTIFY: { notify_payload_t *notify_payload = (notify_payload_t *) payload; - this->logger->log(this->logger, CONTROL|LEVEL1, "Process notify type %s for protocol %s", - mapping_find(notify_message_type_m, notify_payload->get_notify_message_type(notify_payload)), - mapping_find(protocol_id_m, notify_payload->get_protocol_id(notify_payload))); - - if (notify_payload->get_protocol_id(notify_payload) != IKE) + status = this->process_notify_payload(this, notify_payload); + if (status != SUCCESS) { - this->logger->log(this->logger, ERROR | LEVEL1, "Notify not for IKE protocol."); payloads->destroy(payloads); - return DELETE_ME; - } - switch (notify_payload->get_notify_message_type(notify_payload)) - { - default: - { - this->logger->log(this->logger, CONTROL|LEVEL1, "Processing of notify type %s not yet implemented", - mapping_find(notify_message_type_m, notify_payload->get_notify_message_type(notify_payload))); - break; - } + return status; } } default: { - this->logger->log(this->logger, CONTROL | LEVEL1, "Processing of Payload with Type number %d not implemented",payload->get_type(payload)); + this->logger->log(this->logger, ERROR|LEVEL1, "Ignoring payload %s (%d)", + mapping_find(payload_type_m, payload->get_type(payload)), payload->get_type(payload)); break; } } } payloads->destroy(payloads); - this->logger->log(this->logger, CONTROL | LEVEL1, "Going to process received payloads"); + /* check if we have all payloads */ + if (!(sa_request && ke_request && nonce_request)) + { + this->logger->log(this->logger, AUDIT, "IKE_SA_INIT request did not contain all required payloads. Deleting IKE_SA"); + return DELETE_ME; + } + this->ike_sa->build_message(this->ike_sa, IKE_SA_INIT, FALSE, &response); status = this->build_sa_payload(this, sa_request, response); @@ -300,7 +291,7 @@ static status_t process_message(private_responder_init_t *this, message_t *messa status = this->ike_sa->send_response(this->ike_sa, response); if (status != SUCCESS) { - this->logger->log(this->logger, ERROR, "Could not send response message"); + this->logger->log(this->logger, AUDIT, "Unable to send IKE_SA_INIT response. Deleting IKE_SA"); response->destroy(response); return DELETE_ME; } @@ -312,14 +303,11 @@ static status_t process_message(private_responder_init_t *this, message_t *messa ike_sa_init_response_data = response->get_packet_data(response); ike_sa_init_request_data = message->get_packet_data(message); - next_state = ike_sa_init_responded_create(this->ike_sa, this->received_nonce, this->sent_nonce,ike_sa_init_request_data,ike_sa_init_response_data); + next_state = ike_sa_init_responded_create(this->ike_sa, this->received_nonce, this->sent_nonce,ike_sa_init_request_data, + ike_sa_init_response_data); /* state can now be changed */ this->ike_sa->set_new_state(this->ike_sa, (state_t *) next_state); - /* state has NOW changed :-) */ - this->logger->log(this->logger, CONTROL|LEVEL1, "Changed state of IKE_SA from %s to %s",mapping_find(ike_sa_state_m,RESPONDER_INIT),mapping_find(ike_sa_state_m,IKE_SA_INIT_RESPONDED) ); - - this->logger->log(this->logger, CONTROL|LEVEL2, "Destroy old sate object"); this->destroy_after_state_change(this); return SUCCESS; @@ -344,8 +332,8 @@ static status_t build_sa_payload(private_responder_init_t *this,sa_payload_t *sa status = sa_request->get_ike_proposals (sa_request, &ike_proposals,&proposal_count); if (status != SUCCESS) { - this->logger->log(this->logger, ERROR | LEVEL1, "SA payload does not contain IKE proposals"); - this->send_notify_reply(this,NO_PROPOSAL_CHOSEN,CHUNK_INITIALIZER); + this->logger->log(this->logger, AUDIT, "IKE_SA_INIT request did not contain any proposals. Deleting IKE_SA"); + this->ike_sa->send_notify(this->ike_sa, IKE_SA_INIT, NO_PROPOSAL_CHOSEN, CHUNK_INITIALIZER); return DELETE_ME; } @@ -353,8 +341,8 @@ static status_t build_sa_payload(private_responder_init_t *this,sa_payload_t *sa allocator_free(ike_proposals); if (status != SUCCESS) { - this->logger->log(this->logger, ERROR | LEVEL1, "No proposal of suggested proposals selected"); - this->send_notify_reply(this,NO_PROPOSAL_CHOSEN,CHUNK_INITIALIZER); + this->logger->log(this->logger, AUDIT, "IKE_SA_INIT request did not contain any acceptable proposals. Deleting IKE_SA"); + this->ike_sa->send_notify(this->ike_sa, IKE_SA_INIT, NO_PROPOSAL_CHOSEN, CHUNK_INITIALIZER); return DELETE_ME; } @@ -363,7 +351,7 @@ static status_t build_sa_payload(private_responder_init_t *this,sa_payload_t *sa status = this->ike_sa->create_transforms_from_proposal(this->ike_sa,&(selected_proposal)); if (status != SUCCESS) { - this->logger->log(this->logger, ERROR | LEVEL1, "Transform objects could not be created from selected proposal"); + this->logger->log(this->logger, AUDIT, "Transform objects could not be created from selected proposal. Deleting IKE_SA"); return DELETE_ME; } @@ -392,7 +380,7 @@ static status_t build_ke_payload(private_responder_init_t *this,ke_payload_t *ke if (group == MODP_UNDEFINED) { - this->logger->log(this->logger, ERROR | LEVEL1, "Diffie hellman group set to undefined!"); + this->logger->log(this->logger, AUDIT, "No diffie hellman group to select. Deleting IKE_SA"); return DELETE_ME; } if (this->dh_group_number != group) @@ -401,12 +389,12 @@ static status_t build_ke_payload(private_responder_init_t *this,ke_payload_t *ke chunk_t accepted_group_chunk; /* group not same as selected one * Maybe key exchange payload is before SA payload */ - this->logger->log(this->logger, ERROR | LEVEL1, "Diffie hellman group not as in selected proposal!"); + this->logger->log(this->logger, AUDIT, "IKE_SA_INIT request did not contain a acceptable diffie hellman group. Deleting IKE_SA"); accepted_group = htons(this->dh_group_number); accepted_group_chunk.ptr = (u_int8_t*) &(accepted_group); accepted_group_chunk.len = 2; - this->send_notify_reply(this,INVALID_KE_PAYLOAD,accepted_group_chunk); + this->ike_sa->send_notify(this->ike_sa,IKE_SA_INIT,INVALID_KE_PAYLOAD,accepted_group_chunk); return DELETE_ME; } @@ -414,7 +402,8 @@ static status_t build_ke_payload(private_responder_init_t *this,ke_payload_t *ke dh = diffie_hellman_create(group); if (dh == NULL) { - this->logger->log(this->logger, ERROR, "Could not generate DH object with group %d",mapping_find(diffie_hellman_group_m,group) ); + this->logger->log(this->logger, AUDIT, "Could not generate DH object with group %d. Deleting IKE_SA", + mapping_find(diffie_hellman_group_m,group) ); return DELETE_ME; } this->logger->log(this->logger, CONTROL | LEVEL2, "Set other DH public value"); @@ -440,7 +429,7 @@ static status_t build_ke_payload(private_responder_init_t *this,ke_payload_t *ke } /** - * Implementation of private_initiator_init_t.build_nonce_payload. + * Implementation of private_responder_init_t.build_nonce_payload. */ static status_t build_nonce_payload(private_responder_init_t *this,nonce_payload_t *nonce_request, message_t *response) { @@ -469,6 +458,32 @@ static status_t build_nonce_payload(private_responder_init_t *this,nonce_payload return SUCCESS; } +/** + * Implementation of private_responder_init_t.process_notify_payload. + */ +static status_t process_notify_payload(private_responder_init_t *this, notify_payload_t *notify_payload) +{ + notify_message_type_t notify_message_type = notify_payload->get_notify_message_type(notify_payload); + + this->logger->log(this->logger, CONTROL|LEVEL1, "Process notify type %s for protocol %s", + mapping_find(notify_message_type_m, notify_message_type), + mapping_find(protocol_id_m, notify_payload->get_protocol_id(notify_payload))); + + if (notify_payload->get_protocol_id(notify_payload) != IKE) + { + this->logger->log(this->logger, ERROR | LEVEL1, "Notify reply not for IKE protocol."); + return FAILED; + } + switch (notify_message_type) + { + default: + { + this->logger->log(this->logger, CONTROL, "IKE_SA_INIT request contained a notify (%d), ignored.", + notify_message_type); + return SUCCESS; + } + } +} /** * Implementation of state_t.get_state. @@ -478,44 +493,6 @@ static ike_sa_state_t get_state(private_responder_init_t *this) return RESPONDER_INIT; } -/** - * Implementation of private_initiator_init_t.send_notify_reply. - */ -static void send_notify_reply (private_responder_init_t *this,notify_message_type_t type, chunk_t data) -{ - notify_payload_t *payload; - message_t *response; - packet_t *packet; - status_t status; - - this->logger->log(this->logger, CONTROL|LEVEL2, "Going to build message with notify payload"); - /* set up the reply */ - this->ike_sa->build_message(this->ike_sa, IKE_SA_INIT, FALSE, &response); - payload = notify_payload_create_from_protocol_and_type(IKE,type); - if ((data.ptr != NULL) && (data.len > 0)) - { - this->logger->log(this->logger, CONTROL|LEVEL2, "Add Data to notify payload"); - payload->set_notification_data(payload,data); - } - - this->logger->log(this->logger, CONTROL|LEVEL2, "Add Notify payload to message"); - response->add_payload(response,(payload_t *) payload); - - /* generate packet */ - this->logger->log(this->logger, CONTROL|LEVEL2, "Gnerate packet from message"); - status = response->generate(response, NULL, NULL, &packet); - if (status != SUCCESS) - { - this->logger->log(this->logger, ERROR, "Could not generate packet from message"); - return; - } - - this->logger->log(this->logger, CONTROL|LEVEL2, "Add packet to global send queue"); - charon->send_queue->add(charon->send_queue, packet); - this->logger->log(this->logger, CONTROL|LEVEL2, "Destroy message"); - response->destroy(response); -} - /** * Implementation of state_t.destroy. */ @@ -572,7 +549,7 @@ responder_init_t *responder_init_create(protected_ike_sa_t *ike_sa) this->build_ke_payload = build_ke_payload; this->build_nonce_payload = build_nonce_payload; this->destroy_after_state_change = destroy_after_state_change; - this->send_notify_reply = send_notify_reply; + this->process_notify_payload = process_notify_payload; /* private data */ this->ike_sa = ike_sa;