- logging cleanup in states
authorMartin Willi <martin@strongswan.org>
Wed, 7 Dec 2005 11:49:54 +0000 (11:49 -0000)
committerMartin Willi <martin@strongswan.org>
Wed, 7 Dec 2005 11:49:54 +0000 (11:49 -0000)
Source/charon/encoding/message.c
Source/charon/sa/states/ike_auth_requested.c
Source/charon/sa/states/ike_sa_init_requested.c
Source/charon/sa/states/ike_sa_init_requested.h
Source/charon/sa/states/ike_sa_init_responded.c
Source/charon/sa/states/initiator_init.c
Source/charon/sa/states/responder_init.c

index cb4db5b..b67f06d 100644 (file)
@@ -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 %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));
index 199a062..ddcff4c 100644 (file)
@@ -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;
                        }
                }
index f86170a..c24ff5b 100644 (file)
@@ -179,6 +179,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;
index b2456c9..7d4df6b 100644 (file)
@@ -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 {
index b3680da..9e4efaf 100644 (file)
@@ -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;
                        }
index ae23df9..6ab698f 100644 (file)
@@ -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);
 }
 
index 940a87a..a54b486 100644 (file)
@@ -121,6 +121,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,51 +458,39 @@ static status_t build_nonce_payload(private_responder_init_t *this,nonce_payload
        return SUCCESS;
 }
 
-
 /**
- * Implementation of  state_t.get_state.
+ * Implementation of private_responder_init_t.process_notify_payload.
  */
-static ike_sa_state_t get_state(private_responder_init_t *this)
+static status_t process_notify_payload(private_responder_init_t *this, notify_payload_t *notify_payload)
 {
-       return RESPONDER_INIT;
+       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 private_initiator_init_t.send_notify_reply.
+ * Implementation of  state_t.get_state.
  */
-static void send_notify_reply (private_responder_init_t *this,notify_message_type_t type, chunk_t data)
+static ike_sa_state_t get_state(private_responder_init_t *this)
 {
-       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);
+       return RESPONDER_INIT;
 }
 
 /**
@@ -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;