src/sslproxysession.cpp

   1 /*
   2  * @file  sslproxysession.cpp
   3  * @brief module of SSLproxy_session
   4  * @brief SSL handshaking and Connecting.
   5  * @brief Client and Server data read/write.
   6  *
   7  * Copyright (C) 2008  NTT COMWARE Corporation.
   8  *
   9  * This program is free software; you can redistribute it and/or
  10  * modify it under the terms of the GNU Lesser General Public
  11  * License as published by the Free Software Foundation; either
  12  * version 2.1 of the License, or (at your option) any later version.
  13  *
  14  * This program is distributed in the hope that it will be useful,
  15  * but WITHOUT ANY WARRANTY; without even the implied warranty of
  16  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
  17  * Lesser General Public License for more details.
  18  *
  19  * You should have received a copy of the GNU Lesser General Public
  20  * License along with this library; if not, write to the Free Software
  21  * Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA
  22  * 02110-1301 USA
  23  *
  24  **********************************************************************
  25  *
  26  * Distributed under the Boost Software Licence, Version 1.0
  27  * http://www.boost.org/LICENSE_1_0.txt
  28  *
  29  **********************************************************************/
  30
  31 #include <sys/syscall.h>        // for SYS_gettid
  32 #include <boost/lexical_cast.hpp>
  33
  34 #include "sslproxyserver.h"
  35 #include "sslproxysession.h"
  36 #include "http_message.h"
  37 #include "http_request.h"
  38 #include "http_response.h"
  39
  40 // sslproxy_session constructor
  41 /*!
  42  * SSLproxy_session constructor.
  43  *
  44  * @param[in]   io_service      IO event dispatcher
  45  * @param[in]   context         SSL context
  46  * @param[in]   itr             endpoint iterator
  47  */
  48 sslproxy_session::sslproxy_session(boost::asio::io_service& ioservice,
  49                                    boost::asio::ssl::context& context,
  50                                    boost::asio::ip::tcp::resolver::iterator itr)
  51                                    :
  52                                    server_socket(ioservice),
  53                                    client_socket(ioservice, context),
  54                                    endpoint_iterator(itr),
  55                                    timer(ioservice),
  56                                    cancel_time(timeout_sec),
  57                                    handshaked(false),
  58                                    istimeout(false),
  59                                    c_r_event(false),
  60                                    c_w_event(false),
  61                                    s_r_event(false),
  62                                    s_w_event(false),
  63                                    finishing(false),
  64                                    cache_timer(ioservice)
  65 {
  66         /*-------- DEBUG LOG --------*/
  67         if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
  68                 LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 1,
  69                         "in/out_function : Constructor sslproxy_session::sslproxy_session("
  70                         "boost::asio::io_service& ioservice, "
  71                         "boost::asio::ssl::context& context, "
  72                         "boost::asio::ip::tcp::resolver::iterator itr)");
  73         }
  74         /*------ DEBUG LOG END ------*/
  75         pthread_mutex_init(&client_socket_mutex, NULL);
  76 }
  77
  78 /*!
  79  * SSLproxy_session destructor.
  80  */
  81 sslproxy_session::~sslproxy_session()
  82 {
  83         /*-------- DEBUG LOG --------*/
  84         if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
  85                 LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 2,
  86                         "in/out_function : Destructor sslproxy_session::~sslproxy_session("
  87                         "void)");
  88         }
  89         /*------ DEBUG LOG END ------*/
  90 }
  91
  92 /*!
  93  * Low level socket getting function.
  94  *
  95  * @return      password string
  96  * @retval      ssl_socket::lowest_layer_type&
  97  */
  98 ssl_socket::lowest_layer_type& sslproxy_session::low_socket()
  99 {
 100         /*-------- DEBUG LOG --------*/
 101         if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 102                 LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 3,
 103                         "in_function : ssl_socket::lowest_layer_type& sslproxy_session::low_socket("
 104                         "void)");
 105         }
 106         /*------ DEBUG LOG END ------*/
 107
 108         try {
 109                 ssl_socket::lowest_layer_type& sock = client_socket.lowest_layer();
 110                 /*-------- DEBUG LOG --------*/
 111                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 112                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 4,
 113                                 "function : ssl_socket::lowest_layer_type& sslproxy_session::low_socket() : "
 114                                 "lowest_layer() END.");
 115                 }
 116                 /*------ DEBUG LOG END ------*/
 117
 118                 /*-------- DEBUG LOG --------*/
 119                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 120                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 5,
 121                                 "out_function : ssl_socket::lowest_layer_type& sslproxy_session::low_socket("
 122                                 "void)");
 123                 }
 124                 /*------ DEBUG LOG END ------*/
 125                 return sock;
 126         } catch (std::exception& e) {
 127                 LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 1,
 128                         "Get low level socket error : %s.", e.what());
 129                 throw -1;
 130         }
 131 }
 132
 133 /*!
 134  * Get remote endpoint string.
 135  * get client address:port from SSL socket
 136  *
 137  * @param[in]   socket  client SSL socket
 138  * @return      endpoint string
 139  */
 140 std::string sslproxy_session::get_remote_endpoint(ssl_socket& socket)
 141 {
 142         /*-------- DEBUG LOG --------*/
 143         if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 144                 LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 6,
 145                         "in_function : std::string sslproxy_session::get_remote_endpoint("
 146                         "ssl_socket& socket)");
 147         }
 148         /*------ DEBUG LOG END ------*/
 149
 150         std::string endpoint_str = "";
 151         boost::asio::ip::tcp::endpoint endpoint;
 152         std::string address;
 153         std::string port;
 154
 155         try {
 156                 try {
 157                         endpoint = socket.lowest_layer().remote_endpoint();
 158                         /*-------- DEBUG LOG --------*/
 159                         if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 160                                 LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 7,
 161                                         "function : std::string sslproxy_session::get_remote_endpoint() : "
 162                                         "lowest_layer().remote_endpoint() END.");
 163                         }
 164                         /*------ DEBUG LOG END ------*/
 165                 } catch (std::exception& e) {
 166                         LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 2,
 167                                 "Get remote endpoint from socket error : %s.", e.what());
 168                         throw -1;
 169                 }
 170
 171                 try {
 172                         address = endpoint.address().to_string();
 173                         /*-------- DEBUG LOG --------*/
 174                         if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 175                                 LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 8,
 176                                         "function : std::string sslproxy_session::get_remote_endpoint() : "
 177                                         "address().to_string() END.");
 178                         }
 179                         /*------ DEBUG LOG END ------*/
 180                 } catch (std::exception& e) {
 181                         LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 3,
 182                                 "Get address string error : %s.", e.what());
 183                         throw -1;
 184                 }
 185
 186                 try {
 187                         port = boost::lexical_cast<std::string>(endpoint.port());
 188                         /*-------- DEBUG LOG --------*/
 189                         if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 190                                 LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 9,
 191                                         "function : std::string sslproxy_session::get_remote_endpoint() : "
 192                                         "lexical_cast(port()) END.");
 193                         }
 194                         /*------ DEBUG LOG END ------*/
 195                 } catch (std::exception& e) {
 196                         LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 4,
 197                                 "Get port string error : %s.", e.what());
 198                         throw -1;
 199                 }
 200
 201                 endpoint_str = address + ":" + port;
 202                 /*-------- DEBUG LOG --------*/
 203                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 204                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 10,
 205                                 "function : std::string sslproxy_session::get_remote_endpoint() : "
 206                                 "Get remote endpoint string END.");
 207                 }
 208                 /*------ DEBUG LOG END ------*/
 209
 210         } catch (int e) {
 211                 /*-------- DEBUG LOG --------*/
 212                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 213                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 11,
 214                                 "function : std::string sslproxy_session::get_remote_endpoint() : "
 215                                 "get_remote_endpoint() error.");
 216                 }
 217                 /*------ DEBUG LOG END ------*/
 218         }
 219
 220         /*-------- DEBUG LOG --------*/
 221         if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 222                 LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 12,
 223                         "out_function : std::string sslproxy_session::get_remote_endpoint("
 224                         "ssl_socket& socket) : "
 225                         "return value = %s",
 226                         endpoint_str.c_str());
 227         }
 228         /*------ DEBUG LOG END ------*/
 229         return endpoint_str;
 230 }
 231
 232 /*!
 233  * Session start function.
 234  * Start async handshake and Set handshake timer
 235  */
 236 void sslproxy_session::start()
 237 {
 238         /*-------- DEBUG LOG --------*/
 239         if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 240                 LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 13,
 241                         "in_function : void sslproxy_session::start(void)");
 242         }
 243         /*------ DEBUG LOG END ------*/
 244
 245         // Output connection log. (info level)
 246         if (conn_log_flag == "on") {
 247                 LOGGER_PUT_LOG_INFO(LOG_CAT_SSLPROXY_CONNECTION, 1,
 248                         "Connect from [%s] to [%s]. %s",
 249                         get_remote_endpoint(client_socket).c_str(),
 250                         target_endpoint.c_str(), target_id.c_str());
 251         }
 252
 253         try {
 254                 if(sessionTable.end() != sessionTable.find((long)this)) {
 255                         // Start async handshake and Set handshake handler.
 256                         client_socket.async_handshake(boost::asio::ssl::stream_base::server,
 257                                                       boost::bind(&sslproxy_session::handle_handshake,
 258                                                                   this,
 259                                                                   boost::asio::placeholders::error));
 260                         /*-------- DEBUG LOG --------*/
 261                         if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 262                                 LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 14,
 263                                         "function : void sslproxy_session::start() : "
 264                                         "async_handshake() registration END.");
 265                         }
 266                         /*------ DEBUG LOG END ------*/
 267
 268                         // Set handshake expire time.
 269                         try {
 270                                 timer.expires_from_now(boost::posix_time::seconds(cancel_time));
 271                                 /*-------- DEBUG LOG --------*/
 272                                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 273                                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 15,
 274                                                 "function : void sslproxy_session::start() : "
 275                                                 "expires_from_now() END. "
 276                                                 "cancel_time = %d",
 277                                                 cancel_time);
 278                                 }
 279                                 /*------ DEBUG LOG END ------*/
 280                         } catch (std::exception& e) {
 281                                 LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 5,
 282                                         "Set handshake expire time error : %s.", e.what());
 283                                 throw -1;
 284                         }
 285
 286                         // Start timer waiting and Set timer handler.
 287                         timer.async_wait(boost::bind(&sslproxy_session::cancel,
 288                                                      this,
 289                                                      boost::asio::placeholders::error));
 290                         /*-------- DEBUG LOG --------*/
 291                         if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 292                                 LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 16,
 293                                         "function : void sslproxy_session::start() : "
 294                                         "async_wait() END.");
 295                         }
 296                         /*------ DEBUG LOG END ------*/
 297                 }
 298         } catch (...) {
 299                 LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 6,
 300                         "Exception occured in sslproxy_session::start().");
 301                 destroy_session(this);
 302         }
 303
 304         /*-------- DEBUG LOG --------*/
 305         if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 306                 LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 17,
 307                         "outfunction : void sslproxy_session::start(void)");
 308         }
 309         /*------ DEBUG LOG END ------*/
 310 }
 311
 312 /*!
 313  * Handshake timeout handler function.
 314  *
 315  * @param[in]   error   error code
 316  */
 317 void sslproxy_session::cancel(const boost::system::error_code& error)
 318 {
 319         // Check session is not already delete.
 320         if(sessionTable.end() != sessionTable.find((long)this)) {
 321                 // Check timout and finishing status.
 322                 if (istimeout || finishing) {
 323                         destroy_session(this);
 324                 } else {
 325                         /*-------- DEBUG LOG --------*/
 326                         if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 327                                 LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 18,
 328                                         "in_function : void sslproxy_session::cancel("
 329                                         "const boost::system::error_code& error) : "
 330                                         "error = %d, handshaked = %d",
 331                                         error.value(), handshaked);
 332                         }
 333                         /*------ DEBUG LOG END ------*/
 334
 335                         if (!error) {
 336                                 // Check session is not already delete.
 337                                 if(sessionTable.end() != sessionTable.find((long)this)) {
 338                                         // Check handshaked.
 339                                         if (!handshaked) {
 340                                                 // When handshake not finished then timer is timeout.
 341                                                 LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 7,
 342                                                         "Handshake timer wait : %d giveup.", cancel_time);
 343                                                 istimeout = true;
 344                                                 client_socket.lowest_layer().cancel();
 345                                         } else {
 346                                                 // When handshake finished then timer is diable.
 347                                                 /*-------- DEBUG LOG --------*/
 348                                                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 349                                                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 19,
 350                                                                 "function : void sslproxy_session::cancel() : "
 351                                                                 "Handshake timer is cancel.");
 352                                                 }
 353                                                 /*------ DEBUG LOG END ------*/
 354                                         }
 355                                 }
 356                         } else {
 357                                 if (error.value() == ECANCELED) {
 358                                         LOGGER_PUT_LOG_INFO(LOG_CAT_SSLPROXY_SESSION, 1,
 359                                                 "Handshake timer operation cancel. Normal END : %s.",
 360                                                 error.message().c_str());
 361                                 } else {
 362                                         LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 8,
 363                                                 "Handshake timer wait NG : %s.",
 364                                                 error.message().c_str());
 365                                 }
 366                         }
 367
 368                         /*-------- DEBUG LOG --------*/
 369                         if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 370                                 LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 20,
 371                                         "out_function : void sslproxy_session::cancel("
 372                                         "const boost::system::error_code& error)");
 373                         }
 374                         /*------ DEBUG LOG END ------*/
 375                 }
 376         }
 377 }
 378
 379 /*!
 380  * Session cache expire handler function.
 381  *
 382  * @param[in]   error   error code
 383  */
 384 void sslproxy_session::cache_expire(const boost::system::error_code& error)
 385 {
 386         // Check session is not already delete.
 387         if(sessionTable.end() != sessionTable.find((long)this)) {
 388                 if (!error) {
 389                         // Server event remain.
 390                         server_socket.cancel();
 391                 } else {
 392                         if (error.value() == ECANCELED) {
 393                                 LOGGER_PUT_LOG_INFO(LOG_CAT_SSLPROXY_SESSION, 8,
 394                                         "Cache expire operation cancel. Normal END : %s.",
 395                                         error.message().c_str());
 396                         } else {
 397                                 LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 22,
 398                                         "Cache expire wait NG : %s.",
 399                                         error.message().c_str());
 400                         }
 401                 }
 402
 403         }
 404 }
 405
 406 /*!
 407  * Destroy session function.
 408  *
 409  * @param[in]   session session object
 410  */
 411 void sslproxy_session::destroy_session(sslproxy_session* session)
 412 {
 413         /*-------- DEBUG LOG --------*/
 414         if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 415                 LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 21,
 416                         "in_function : void sslproxy_session::destroy_session("
 417                         "sslproxy_session* session)");
 418         }
 419         /*------ DEBUG LOG END ------*/
 420
 421         // Check session is not already delete.
 422         if(sessionTable.end() != sessionTable.find((long)session)) {
 423                 finishing = true;
 424                 if (!c_r_event && !c_w_event && !s_r_event && !s_w_event) {
 425                         // All event end.
 426                         pthread_mutex_lock(&sessionTable_mutex);
 427                         sessionTable.erase((long)session);
 428                         pthread_mutex_unlock(&sessionTable_mutex);
 429                         pthread_mutex_lock(&client_socket_mutex);
 430                         delete session;
 431                 } else {
 432                         // Event remain.
 433                         if (c_r_event || c_w_event) {
 434                                 // Client event remain.
 435                                 if (!istimeout) {
 436                                         client_socket.lowest_layer().cancel();
 437                                 }
 438                         } else if (s_r_event || s_w_event) {
 439                                 // Server event remain.
 440                                 // Set expire time for session cache.
 441                                 cache_timer.expires_from_now(boost::posix_time::seconds(session_cache_timeout));
 442                                 cache_timer.async_wait(boost::bind(&sslproxy_session::cache_expire,
 443                                                              this,
 444                                                              boost::asio::placeholders::error));
 445                         }
 446                 }
 447         }
 448 }
 449
 450 /*!
 451  * Hnadshake handling function.
 452  * Check hendshake result and Start async connect.
 453  *
 454  * @param[in]   error   error code
 455  */
 456 void sslproxy_session::handle_handshake(const boost::system::error_code& error)
 457 {
 458         // Check timout and finishing status.
 459         if (istimeout || finishing) {
 460                 destroy_session(this);
 461         } else {
 462                 /*-------- DEBUG LOG --------*/
 463                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 464                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 22,
 465                                 "in_function : void sslproxy_session::handle_handshake("
 466                                 "const boost::system::error_code& error) : "
 467                                 "error = %d, istimeout = %d",
 468                                 error.value(), istimeout);
 469                 }
 470                 /*------ DEBUG LOG END ------*/
 471
 472                 try {
 473                         // Check handshake result.
 474                         if (!error) {
 475                                 // Connect to server after handshake
 476                                 boost::asio::ip::tcp::resolver::iterator end;
 477                                 if (endpoint_iterator != end) {
 478                                         // Start async connect
 479                                         server_socket.async_connect(*endpoint_iterator++,
 480                                                                     boost::bind(&sslproxy_session::handle_connect,
 481                                                                                 this,
 482                                                                                 boost::asio::placeholders::error));
 483                                         /*-------- DEBUG LOG --------*/
 484                                         if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 485                                                 LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 23,
 486                                                         "function : void sslproxy_session::handle_handshake() : "
 487                                                         "async_connect() registration END.");
 488                                         }
 489                                         /*------ DEBUG LOG END ------*/
 490                                 } else {
 491                                         LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 9,
 492                                                 "Server endpoint is nothing for connect.");
 493                                         destroy_session(this);
 494                                 }
 495                         } else {
 496                                 LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 10,
 497                                         "Handshaking NG : %s.",
 498                                         error.message().c_str());
 499                                 destroy_session(this);
 500                         }
 501
 502                 } catch (...) {
 503                         LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 11,
 504                                 "Exception occured in sslproxy_session::handle_handshake().");
 505                         destroy_session(this);
 506                 }
 507
 508                 /*-------- DEBUG LOG --------*/
 509                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 510                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 24,
 511                                 "out_function : void sslproxy_session::handle_handshake("
 512                                 "const boost::system::error_code& error)");
 513                 }
 514                 /*------ DEBUG LOG END ------*/
 515         }
 516 }
 517
 518 /*!
 519  * Connect handling function.
 520  * Check connect result and Start async read client.
 521  *
 522  * @param[in]   error   error code
 523  */
 524 void sslproxy_session::handle_connect(const boost::system::error_code& error)
 525 {
 526         // Check timout and finishing status.
 527         if (istimeout || finishing) {
 528                 destroy_session(this);
 529         } else {
 530                 /*-------- DEBUG LOG --------*/
 531                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 532                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 25,
 533                                 "in_function : void sslproxy_session::handle_connect("
 534                                 "const boost::system::error_code& error) : "
 535                                 "error = %d, istimeout = %d",
 536                                 error.value(), istimeout);
 537                 }
 538                 /*------ DEBUG LOG END ------*/
 539
 540                 try {
 541                         // Check connect result.
 542                         if (!error) {
 543                                 handshaked = true;
 544                                 timer.cancel();
 545                                 // Start async read client.
 546                                 c_r_event = true;
 547                                 pthread_mutex_lock(&client_socket_mutex);
 548                                 client_socket.async_read_some(boost::asio::buffer(client_buffer, MAX_READ_SIZE),
 549                                                               boost::bind(&sslproxy_session::handle_client_read,
 550                                                                           this,
 551                                                                           boost::asio::placeholders::error,
 552                                                                           boost::asio::placeholders::bytes_transferred));
 553                                 pthread_mutex_unlock(&client_socket_mutex);
 554                                 /*-------- DEBUG LOG --------*/
 555                                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 556                                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 26,
 557                                                 "function : void sslproxy_session::handle_connect() : "
 558                                                 "Client async_read_some() registration END.");
 559                                 }
 560                                 /*------ DEBUG LOG END ------*/
 561
 562                                 // Start async read server.
 563                                 s_r_event = true;
 564                                 server_socket.async_read_some(boost::asio::buffer(server_buffer, MAX_READ_SIZE),
 565                                                               boost::bind(&sslproxy_session::handle_server_read,
 566                                                                           this,
 567                                                                           boost::asio::placeholders::error,
 568                                                                           boost::asio::placeholders::bytes_transferred));
 569                                 /*-------- DEBUG LOG --------*/
 570                                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 571                                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 27,
 572                                                 "function : void sslproxy_session::handle_connect() : "
 573                                                 "Server async_read_some() registration END.");
 574                                 }
 575                                 /*------ DEBUG LOG END ------*/
 576                         } else {
 577                                 boost::asio::ip::tcp::resolver::iterator end;
 578                                 if (endpoint_iterator != end) {
 579                                         // Retry connect to server
 580                                         LOGGER_PUT_LOG_WARN(LOG_CAT_SSLPROXY_SESSION, 1,
 581                                                 "Connecting NG : %s. Retry connect.",
 582                                                 error.message().c_str());
 583                                         server_socket.async_connect(*endpoint_iterator++,
 584                                                                     boost::bind(&sslproxy_session::handle_connect,
 585                                                                                 this,
 586                                                                                 boost::asio::placeholders::error));
 587                                         /*-------- DEBUG LOG --------*/
 588                                         if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 589                                                 LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 28,
 590                                                         "function : void sslproxy_session::handle_connect() : "
 591                                                         "async_connect() retry registration END.");
 592                                         }
 593                                         /*------ DEBUG LOG END ------*/
 594                                 } else {
 595                                         LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 12,
 596                                                 "Connecting NG : %s.",
 597                                                 error.message().c_str());
 598                                         destroy_session(this);
 599                                 }
 600                         }
 601                 } catch (...) {
 602                         LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 13,
 603                                 "Exception occured in void sslproxy_session::handle_connect().");
 604                         destroy_session(this);
 605                 }
 606
 607                 /*-------- DEBUG LOG --------*/
 608                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 609                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 29,
 610                                 "out_function : void sslproxy_session::handle_connect("
 611                                 "const boost::system::error_code& error)");
 612                 }
 613                 /*------ DEBUG LOG END ------*/
 614         }
 615 }
 616
 617 /*!
 618  * Client read handling function.
 619  * Check client read result and Start async write server.
 620  *
 621  * @param[in]   error                   error code
 622  * @param[in]   bytes_transferred       transferred data size
 623  */
 624 void sslproxy_session::handle_client_read(const boost::system::error_code& error,
 625                                           size_t bytes_transferred)
 626 {
 627         c_r_event = false;
 628         // Check timout and finishing status.
 629         if (istimeout || finishing) {
 630                 destroy_session(this);
 631         } else {
 632                 /*-------- DEBUG LOG --------*/
 633                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 634                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 30,
 635                                 "in_function : void sslproxy_session::handle_client_read("
 636                                 "const boost::system::error_code& error, "
 637                                 "size_t bytes_transferred) : "
 638                                 "error = %d, bytes_transferred = %d, istimeout = %d",
 639                                 error.value(), (int)bytes_transferred, istimeout);
 640                 }
 641                 /*------ DEBUG LOG END ------*/
 642
 643                 try {
 644                         // Check client read result.
 645                         if (!error) {
 646                                 // Edit client message if necessary.
 647                                 if (edit_client_msg)
 648                                         edit_client_message(bytes_transferred);
 649                                 // Start async write server.
 650                                 s_w_event = true;
 651                                 boost::asio::async_write(server_socket,
 652                                                          boost::asio::buffer(client_buffer, bytes_transferred),
 653                                                          boost::bind(&sslproxy_session::handle_server_write,
 654                                                                      this,
 655                                                                      boost::asio::placeholders::error,
 656                                                                      bytes_transferred));
 657                                 /*-------- DEBUG LOG --------*/
 658                                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 659                                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 31,
 660                                                 "function : void sslproxy_session::handle_client_read() : "
 661                                                 "Server async_write() registration END.");
 662                                 }
 663                                 /*------ DEBUG LOG END ------*/
 664                         } else {
 665                                 if (error.value() == boost::asio::error::eof) {
 666                                         // When End of file. Client data read complete.
 667                                         LOGGER_PUT_LOG_INFO(LOG_CAT_SSLPROXY_SESSION, 2,
 668                                                 "Client data read complete. Normal END : %s.",
 669                                                 error.message().c_str());
 670                                 } else if (error.value() == boost::asio::error::shut_down) {
 671                                         LOGGER_PUT_LOG_INFO(LOG_CAT_SSLPROXY_SESSION, 3,
 672                                                 "Client already shutdown. Normal END : %s.",
 673                                                 error.message().c_str());
 674                                 } else if (error.value() == boost::asio::error::operation_aborted) {
 675                                         LOGGER_PUT_LOG_INFO(LOG_CAT_SSLPROXY_SESSION, 4,
 676                                                 "Client read operation canceled. Normal END : %s.",
 677                                                 error.message().c_str());
 678                                 } else {
 679                                         LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 14,
 680                                                 "Client read NG : %s.",
 681                                                 error.message().c_str());
 682                                 }
 683                                 destroy_session(this);
 684                         }
 685
 686                 } catch (...) {
 687                         LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 15,
 688                                 "Exception occured in void sslproxy_session::handle_client_read().");
 689                         destroy_session(this);
 690                 }
 691
 692                 /*-------- DEBUG LOG --------*/
 693                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 694                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 32,
 695                                 "out_function : void sslproxy_session::handle_client_read("
 696                                 "const boost::system::error_code& error, "
 697                                 "size_t bytes_transferred)");
 698                 }
 699                 /*------ DEBUG LOG END ------*/
 700         }
 701 }
 702
 703 /*!
 704  * Server write handling function.
 705  * Check server write result and Start async read server.
 706  *
 707  * @param[in]   error                   error code
 708  * @param[in]   bytes_transferred       transferred data size
 709  */
 710 void sslproxy_session::handle_server_write(const boost::system::error_code& error,
 711                                            size_t bytes_transferred)
 712 {
 713         s_w_event = false;
 714         // Check timout and finishing status.
 715         if (istimeout || finishing) {
 716                 destroy_session(this);
 717         } else {
 718                 /*-------- DEBUG LOG --------*/
 719                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 720                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 33,
 721                                 "in_function : void sslproxy_session::handle_server_write("
 722                                 "const boost::system::error_code& error, "
 723                                 "size_t bytes_transferred) : "
 724                                 "error = %d, bytes_transferred = %d, istimeout = %d",
 725                                 error.value(), (int)bytes_transferred, istimeout);
 726                 }
 727                 /*------ DEBUG LOG END ------*/
 728
 729                 try {
 730                         // Check server write result.
 731                         if (!error) {
 732                                 // Next client data wait, start async read client again.
 733                                 c_r_event = true;
 734                                 pthread_mutex_lock(&client_socket_mutex);
 735                                 client_socket.async_read_some(boost::asio::buffer(client_buffer, MAX_READ_SIZE),
 736                                                               boost::bind(&sslproxy_session::handle_client_read,
 737                                                                           this,
 738                                                                           boost::asio::placeholders::error,
 739                                                                           boost::asio::placeholders::bytes_transferred));
 740                                 pthread_mutex_unlock(&client_socket_mutex);
 741                                 /*-------- DEBUG LOG --------*/
 742                                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 743                                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 34,
 744                                                 "function : void sslproxy_session::handle_server_write() : "
 745                                                 "Client async_read_some() registration again END.");
 746                                 }
 747                                 /*------ DEBUG LOG END ------*/
 748                         } else {
 749                                 LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 16,
 750                                         "Server write NG : %s.",
 751                                         error.message().c_str());
 752                                 destroy_session(this);
 753                         }
 754
 755                 } catch (...) {
 756                         LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 17,
 757                                 "Exception occured in void sslproxy_session::handle_server_write().");
 758                         destroy_session(this);
 759                 }
 760
 761                 /*-------- DEBUG LOG --------*/
 762                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 763                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 35,
 764                                 "out_function : void sslproxy_session::handle_server_write("
 765                                 "const boost::system::error_code& error, "
 766                                 "size_t bytes_transferred)");
 767                 }
 768                 /*------ DEBUG LOG END ------*/
 769         }
 770 }
 771
 772 /*!
 773  * Server read handling function.
 774  * Check server read result and Start async write client.
 775  *
 776  * @param[in]   error                   error code
 777  * @param[in]   bytes_transferred       transferred data size
 778  */
 779 void sslproxy_session::handle_server_read(const boost::system::error_code& error,
 780                                           size_t bytes_transferred)
 781 {
 782         s_r_event = false;
 783         // Check timout and finishing status.
 784         if (istimeout || finishing) {
 785                 destroy_session(this);
 786         } else {
 787                 /*-------- DEBUG LOG --------*/
 788                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 789                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 36,
 790                                 "in_function : void sslproxy_session::handle_server_read("
 791                                 "const boost::system::error_code& error, "
 792                                 "size_t bytes_transferred) : "
 793                                 "error = %d, bytes_transferred = %d, istimeout = %d",
 794                                 error.value(), (int)bytes_transferred, istimeout);
 795                 }
 796                 /*------ DEBUG LOG END ------*/
 797
 798                 try {
 799                         // Check server read result.
 800                         if (!error) {
 801                                 // Start async write client.
 802                                 c_w_event = true;
 803                                 pthread_mutex_lock(&client_socket_mutex);
 804                                 boost::asio::async_write(client_socket,
 805                                                          boost::asio::buffer(server_buffer, bytes_transferred),
 806                                                          boost::bind(&sslproxy_session::handle_client_write,
 807                                                                      this,
 808                                                                      boost::asio::placeholders::error,
 809                                                                      bytes_transferred));
 810                                 pthread_mutex_unlock(&client_socket_mutex);
 811                                 /*-------- DEBUG LOG --------*/
 812                                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 813                                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 37,
 814                                                 "function : void sslproxy_session::handle_server_read() : "
 815                                                 "Client async_write() registration END.");
 816                                 }
 817                                 /*------ DEBUG LOG END ------*/
 818                         } else {
 819                                 if (error.value() == boost::asio::error::eof) {
 820                                         // When End of file. Server data read complete.
 821                                         LOGGER_PUT_LOG_INFO(LOG_CAT_SSLPROXY_SESSION, 5,
 822                                                 "Server data read complete. Normal END : %s.",
 823                                                 error.message().c_str());
 824                                 } else {
 825                                         LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 18,
 826                                                 "Server read NG : %s.",
 827                                                 error.message().c_str());
 828                                 }
 829                                 destroy_session(this);
 830                         }
 831
 832                 } catch (...) {
 833                         LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 19,
 834                                 "Exception occured in void sslproxy_session::handle_server_read().");
 835                         destroy_session(this);
 836                 }
 837
 838                 /*-------- DEBUG LOG --------*/
 839                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 840                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 38,
 841                                 "out_function : void sslproxy_session::handle_server_read("
 842                                 "const boost::system::error_code& error, "
 843                                 "size_t bytes_transferred)");
 844                 }
 845                 /*------ DEBUG LOG END ------*/
 846         }
 847 }
 848
 849 /*!
 850  * Client write handling function.
 851  * Check client write result and Start async read client.
 852  *
 853  * @param[in]   error                   error code
 854  * @param[in]   bytes_transferred       transferred data size
 855  */
 856 void sslproxy_session::handle_client_write(const boost::system::error_code& error,
 857                                            size_t bytes_transferred)
 858 {
 859         c_w_event = false;
 860         // Check timout and finishing status.
 861         if (istimeout || finishing) {
 862                 destroy_session(this);
 863         } else {
 864                 /*-------- DEBUG LOG --------*/
 865                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 866                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 39,
 867                                 "in_function : void sslproxy_session::handle_client_write("
 868                                 "const boost::system::error_code& error, "
 869                                 "size_t bytes_transferred) : "
 870                                 "error = %d, bytes_transferred = %d, istimeout = %d",
 871                                 error.value(), (int)bytes_transferred, istimeout);
 872                 }
 873                 /*------ DEBUG LOG END ------*/
 874
 875                 try {
 876                         // Check client write result.
 877                         if (!error) {
 878                                 // Next server data wait, start async read server again.
 879                                 s_r_event = true;
 880                                 server_socket.async_read_some(boost::asio::buffer(server_buffer, MAX_READ_SIZE),
 881                                                               boost::bind(&sslproxy_session::handle_server_read,
 882                                                                           this,
 883                                                                           boost::asio::placeholders::error,
 884                                                                           boost::asio::placeholders::bytes_transferred));
 885                                 /*-------- DEBUG LOG --------*/
 886                                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 887                                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 40,
 888                                                 "function : void sslproxy_session::handle_client_write() : "
 889                                                 "Server async_read_some() registration again END.");
 890                                 }
 891                                 /*------ DEBUG LOG END ------*/
 892                         } else {
 893                                 if (error.value() == boost::asio::error::connection_reset) {
 894                                         LOGGER_PUT_LOG_INFO(LOG_CAT_SSLPROXY_SESSION, 6,
 895                                                 "Reset connection. Normal END : %s.",
 896                                                 error.message().c_str());
 897                                 } else if (error.value() == boost::asio::error::broken_pipe) {
 898                                         LOGGER_PUT_LOG_INFO(LOG_CAT_SSLPROXY_SESSION, 7,
 899                                                 "Pipe broken. Normal END : %s.",
 900                                                 error.message().c_str());
 901                                 } else {
 902                                         LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 20,
 903                                                 "Client write NG : %s.",
 904                                                 error.message().c_str());
 905                                 }
 906                                 destroy_session(this);
 907                         }
 908
 909                 } catch (...) {
 910                         LOGGER_PUT_LOG_ERROR(LOG_CAT_SSLPROXY_SESSION, 21,
 911                                 "Exception occured in void sslproxy_session::handle_client_write().");
 912                         destroy_session(this);
 913                 }
 914
 915                 /*-------- DEBUG LOG --------*/
 916                 if (LOG_LV_DEBUG == logger_get_log_level(LOG_CAT_SSLPROXY_SESSION)) {
 917                         LOGGER_PUT_LOG_DEBUG(LOG_CAT_SSLPROXY_SESSION, 41,
 918                                 "out_function : void sslproxy_session::handle_client_write("
 919                                 "const boost::system::error_code& error, "
 920                                 "size_t bytes_transferred)");
 921                 }
 922                 /*------ DEBUG LOG END ------*/
 923         }
 924 }
 925
 926 /*!
 927  * Edit client message function.
 928  * Add, delete or change client message.
 929  *
 930  * @param[in,out]       bytes_transferred       transferred data size before,after edit
 931  */
 932 void sslproxy_session::edit_client_message(size_t& bytes_transferred)
 933 {
 934         if (x_forwarded_for_mode != NONE_X_FORWARDED_FOR ||
 935             custom_field != "") {
 936
 937                 try {
 938                         // Parse HTTP request
 939                         http_request request(std::string(client_buffer, bytes_transferred));
 940                         field_range headers;
 941                         field_map_iterator begin, end;
 942                         std::string xf;
 943
 944                         // Edit X_FORWARDED_FOR header field.
 945                         switch (x_forwarded_for_mode) {
 946                         case NONE_X_FORWARDED_FOR:
 947                                 break;
 948                         case ADD_X_FORWARDED_FOR:
 949                                 headers = request.header("X-Forwarded-For");
 950                                 begin = headers.first;
 951                                 end   = headers.second;
 952                                 if (begin != end) {
 953                                         while (begin != end) {
 954                                                 // Already exist header
 955                                                 request.header("X-Forwarded-For", begin->second + ", " + get_remote_endpoint(client_socket));
 956                                                 begin++;
 957                                         }
 958                                 }
 959                                 else {
 960                                         request.header("X-Forwarded-For", get_remote_endpoint(client_socket));
 961                                 }
 962                                 break;
 963                         case SET_X_FORWARDED_FOR:
 964                                 request.header("X-Forwarded-For", get_remote_endpoint(client_socket));
 965                                 break;
 966                         case DELETE_X_FORWARDED_FOR:
 967                                 request.header("X-Forwarded-For", "");
 968                                 break;
 969                         }
 970
 971                         // Edit X_FORWARDED_FOR header field.
 972                         if (custom_field != "") {
 973                         }
 974
 975                         std::string new_client_buffer = request.as_string();
 976                         if (new_client_buffer.length() <= MAX_BUFFER_SIZE) {
 977                                 memcpy(client_buffer, new_client_buffer.c_str(), new_client_buffer.length());
 978                                 bytes_transferred = new_client_buffer.length();
 979                         }
 980                 }
 981                 catch (...) {
 982                         // XXX http request parse error
 983                 }
 984         }
 985 }