src/sslproxysession.cpp

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