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