From 375108aabfae08257a850251bbc9e2ecc994b471 Mon Sep 17 00:00:00 2001 From: Peter Thorson Date: Sun, 27 Jan 2013 08:20:08 -0600 Subject: [PATCH] Switches cout based logging to logging policy --- websocketpp/connection.hpp | 16 +- websocketpp/endpoint.hpp | 28 +- websocketpp/impl/connection_impl.hpp | 254 ++++++++++++------ websocketpp/impl/endpoint_impl.hpp | 13 +- websocketpp/logger/basic.hpp | 7 +- websocketpp/processors/hybi13.hpp | 10 +- websocketpp/roles/server_endpoint.hpp | 12 +- websocketpp/transport/asio/connection.hpp | 44 +-- websocketpp/transport/asio/endpoint.hpp | 59 ++-- websocketpp/transport/iostream/connection.hpp | 45 ++-- websocketpp/transport/iostream/endpoint.hpp | 32 ++- 11 files changed, 353 insertions(+), 167 deletions(-) diff --git a/websocketpp/connection.hpp b/websocketpp/connection.hpp index e6a47184fe..0a616a3f72 100644 --- a/websocketpp/connection.hpp +++ b/websocketpp/connection.hpp @@ -125,6 +125,11 @@ public: /// Type of the concurrency component of this connection typedef typename config::concurrency_type concurrency_type; + /// Type of the access logging policy + typedef typename config::alog_type alog_type; + /// Type of the error logging policy + typedef typename config::elog_type elog_type; + /// Type of the transport component of this connection typedef typename config::transport_type::transport_con_type transport_con_type; @@ -154,16 +159,19 @@ public: // Misc Convenience Types typedef session::internal_state::value istate_type; - explicit connection(bool is_server, const std::string& ua) - : transport_con_type(is_server) + explicit connection(bool is_server, const std::string& ua, alog_type& alog, + elog_type& elog) + : transport_con_type(is_server,alog,elog) , m_user_agent(ua) , m_state(session::state::CONNECTING) , m_internal_state(session::internal_state::USER_INIT) , m_msg_manager(new con_msg_manager_type()) , m_send_buffer_size(0) , m_is_server(is_server) + , m_alog(alog) + , m_elog(elog) { - std::cout << "connection constructor" << std::endl; + m_alog.write(log::alevel::devel,"connection constructor"); } // Public Interface @@ -859,6 +867,8 @@ private: uri_ptr m_uri; const bool m_is_server; + alog_type& m_alog; + elog_type& m_elog; // Close state /// Close code that was sent on the wire by this endpoint diff --git a/websocketpp/endpoint.hpp b/websocketpp/endpoint.hpp index 5e07df0618..7905bcd4db 100644 --- a/websocketpp/endpoint.hpp +++ b/websocketpp/endpoint.hpp @@ -1,5 +1,5 @@ /* - * Copyright (c) 2012, Peter Thorson. All rights reserved. + * Copyright (c) 2013, Peter Thorson. All rights reserved. * * Redistribution and use in source and binary forms, with or without * modification, are permitted provided that the following conditions are met: @@ -79,7 +79,12 @@ public: : m_user_agent(::websocketpp::user_agent) , m_is_server(is_server) { - std::cout << "endpoint constructor" << std::endl; + m_alog.set_channels(0xffffffff); + m_elog.set_channels(0xffffffff); + + m_alog.write(log::alevel::devel,"endpoint constructor"); + + transport_type::init_logging(&m_elog,&m_alog); } /// Returns the user agent string that this endpoint will use @@ -119,7 +124,7 @@ public: bool is_server() const { return m_is_server; } - + /*************************/ /* Set Handler functions */ /*************************/ @@ -178,9 +183,10 @@ public: ec = error::make_error_code(error::bad_connection); return; } - - std::cout << "Interrupting connection " << con.get() << std::endl; - + + m_alog.write(log::alevel::devel, + "Interrupting connection"+con.get()); + ec = con->interrupt(); } @@ -233,6 +239,9 @@ protected: typedef typename concurrency_type::scoped_lock_type scoped_lock_type; typedef typename concurrency_type::mutex_type mutex_type; + typedef typename config::elog_type elog_type; + typedef typename config::alog_type alog_type; + connection_ptr create_connection(); void remove_connection(connection_ptr con); @@ -251,6 +260,9 @@ protected: hdl.lock()); return con; } + + alog_type m_alog; + elog_type m_elog; private: // dynamic settings std::string m_user_agent; @@ -265,7 +277,9 @@ private: http_handler m_http_handler; validate_handler m_validate_handler; message_handler m_message_handler; - + + + // endpoint resources std::set m_connections; diff --git a/websocketpp/impl/connection_impl.hpp b/websocketpp/impl/connection_impl.hpp index 6876a45139..8474a34eb4 100644 --- a/websocketpp/impl/connection_impl.hpp +++ b/websocketpp/impl/connection_impl.hpp @@ -1,5 +1,5 @@ /* - * Copyright (c) 2012, Peter Thorson. All rights reserved. + * Copyright (c) 2013, Peter Thorson. All rights reserved. * * Redistribution and use in source and binary forms, with or without * modification, are permitted provided that the following conditions are met: @@ -45,7 +45,8 @@ template void connection::set_termination_handler( termination_handler new_handler) { - std::cout << "connection set_termination_handler" << std::endl; + m_alog.write(log::alevel::devel, + "connection set_termination_handler"); //scoped_lock_type lock(m_connection_state_lock); @@ -78,7 +79,7 @@ lib::error_code connection::send(const std::string& payload, template lib::error_code connection::send(typename config::message_type::ptr msg) { - std::cout << "send" << std::endl; + m_alog.write(log::alevel::devel,"connection send"); // TODO: if (m_state != session::state::OPEN) { @@ -122,7 +123,7 @@ lib::error_code connection::send(typename config::message_type::ptr msg) template void connection::ping(const std::string& payload) { - std::cout << "ping" << std::endl; + m_alog.write(log::alevel::devel,"connection ping"); if (m_state != session::state::OPEN) { throw error::make_error_code(error::invalid_state); @@ -154,7 +155,7 @@ void connection::ping(const std::string& payload) { template void connection::pong(const std::string& payload, lib::error_code& ec) { - std::cout << "pong" << std::endl; + m_alog.write(log::alevel::devel,"connection pong"); if (m_state != session::state::OPEN) { ec = error::make_error_code(error::invalid_state); @@ -201,7 +202,7 @@ template void connection::close(const close::status::value code, const std::string & reason, lib::error_code & ec) { - std::cout << "close" << std::endl; + m_alog.write(log::alevel::devel,"connection close"); // check state // check reason length @@ -239,7 +240,7 @@ void connection::close(const close::status::value code, */ template lib::error_code connection::interrupt() { - std::cout << "connection::interrupt" << std::endl; + m_alog.write(log::alevel::devel,"connection connection::interrupt"); return transport_con_type::interrupt( lib::bind( &type::handle_interrupt, @@ -394,7 +395,7 @@ void connection::remove_header( template void connection::start() { - std::cout << "connection start" << std::endl; + m_alog.write(log::alevel::devel,"connection start"); this->atomic_state_change( istate::USER_INIT, @@ -416,7 +417,7 @@ void connection::start() { template void connection::handle_transport_init(const lib::error_code& ec) { - std::cout << "connection handle_transport_init" << std::endl; + m_alog.write(log::alevel::devel,"connection handle_transport_init"); { scoped_lock_type lock(m_connection_state_lock); @@ -438,7 +439,10 @@ void connection::handle_transport_init(const lib::error_code& ec) { } if (ec) { - std::cout << "handle_transport_init recieved error: "<< ec << std::endl; + std::stringstream s; + s << "handle_transport_init recieved error: "<< ec; + m_elog.write(log::elevel::fatal,s.str()); + this->terminate(); return; } @@ -460,7 +464,7 @@ void connection::handle_transport_init(const lib::error_code& ec) { template void connection::read(size_t num_bytes) { - std::cout << "connection read" << std::endl; + m_alog.write(log::alevel::devel,"connection read"); transport_con_type::async_read_at_least( num_bytes, @@ -481,7 +485,7 @@ template void connection::handle_handshake_read(const lib::error_code& ec, size_t bytes_transferred) { - std::cout << "connection handle_handshake_read" << std::endl; + m_alog.write(log::alevel::devel,"connection handle_handshake_read"); this->atomic_state_check( istate::READ_HTTP_REQUEST, @@ -489,14 +493,16 @@ void connection::handle_handshake_read(const lib::error_code& ec, ); if (ec) { - std::cout << "error in handle_read_handshake: "<< ec << std::endl; + std::stringstream s; + s << "error in handle_read_handshake: "<< ec; + m_elog.write(log::elevel::fatal,s.str()); this->terminate(); return; } // Boundaries checking. TODO: How much of this should be done? if (bytes_transferred > config::connection_read_buffer_size) { - std::cout << "Fatal boundaries checking error." << std::endl; + m_elog.write(log::elevel::fatal,"Fatal boundaries checking error."); this->terminate(); return; } @@ -515,15 +521,17 @@ void connection::handle_handshake_read(const lib::error_code& ec, // More paranoid boundaries checking. // TODO: Is this overkill? if (bytes_processed > config::connection_read_buffer_size) { - std::cout << "Fatal boundaries checking error." << std::endl; + m_elog.write(log::elevel::fatal,"Fatal boundaries checking error."); this->terminate(); return; } - std::cout << "bytes_transferred: " << bytes_transferred - << " bytes" << std::endl; - std::cout << "bytes_processed: " << bytes_processed - << " bytes" << std::endl; + if (m_alog.static_test(log::alevel::devel)) { + std::stringstream s; + s << "bytes_transferred: " << bytes_transferred + << " bytes, bytes processed: " << bytes_processed << " bytes"; + m_alog.write(log::alevel::devel,s.str()); + } if (m_request.ready()) { if (!this->initialize_processor()) { @@ -542,7 +550,7 @@ void connection::handle_handshake_read(const lib::error_code& ec, bytes_processed += 8; } else { // TODO: need more bytes - std::cout << "short key3 read" << std::endl; + m_alog.write(log::alevel::devel,"short key3 read"); m_response.set_status(http::status_code::INTERNAL_SERVER_ERROR); this->send_http_response_error(); return; @@ -601,7 +609,7 @@ template void connection::handle_read_frame(const lib::error_code& ec, size_t bytes_transferred) { - std::cout << "connection handle_read_frame" << std::endl; + m_alog.write(log::alevel::devel,"connection handle_read_frame"); this->atomic_state_check( istate::PROCESS_CONNECTION, @@ -609,26 +617,30 @@ void connection::handle_read_frame(const lib::error_code& ec, ); if (ec) { - std::cout << "error in handle_read_frame: " << ec << std::endl; + std::stringstream s; + s << "error in handle_read_frame: " << ec; + m_elog.write(log::elevel::fatal,s.str()); this->terminate(); return; } // Boundaries checking. TODO: How much of this should be done? if (bytes_transferred > config::connection_read_buffer_size) { - std::cout << "Fatal boundaries checking error." << std::endl; + m_elog.write(log::elevel::fatal,"Fatal boundaries checking error"); this->terminate(); return; } size_t p = 0; - std::cout << "p = " << p - << " bytes transferred = " << bytes_transferred << std::endl; + std::stringstream s; + s << "p = " << p << " bytes transferred = " << bytes_transferred; + m_alog.write(log::alevel::devel,s.str()); while (p < bytes_transferred) { - std::cout << "calling consume with " - << bytes_transferred-p << " bytes" << std::endl; + s.str(""); + s << "calling consume with " << bytes_transferred-p << " bytes"; + m_alog.write(log::alevel::devel,s.str()); lib::error_code ec; @@ -638,11 +650,12 @@ void connection::handle_read_frame(const lib::error_code& ec, ec ); - std::cout << "bytes left after consume:" - << bytes_transferred-p << std::endl; + s.str(""); + s << "bytes left after consume: " << bytes_transferred-p; + m_alog.write(log::alevel::devel,s.str()); if (ec) { - std::cout << "consume error: " << ec.message() << std::endl; + m_elog.write(log::elevel::rerror,"consume error: "+ec.message()); if (config::drop_on_protocol_error) { this->terminate(); @@ -652,8 +665,9 @@ void connection::handle_read_frame(const lib::error_code& ec, this->close(processor::error::to_ws(ec),ec.message(),close_ec); if (close_ec) { - std::cout << "Failed to send a close frame after protocol error: " - << close_ec.message() << std::endl; + m_elog.write(log::elevel::fatal, + "Failed to send a close frame after protocol error: " + +close_ec.message()); this->terminate(); return; } @@ -662,12 +676,13 @@ void connection::handle_read_frame(const lib::error_code& ec, } if (m_processor->ready()) { - std::cout << "consume ended in ready" << std::endl; + m_alog.write(log::alevel::devel,"consume ended in ready"); message_ptr msg = m_processor->get_message(); if (!msg) { - std::cout << "null message from m_processor" << std::endl; + m_alog.write(log::alevel::devel, + "null message from m_processor"); } else if (!is_control(msg->get_opcode())) { // data message, dispatch to user if (m_message_handler) { @@ -701,7 +716,7 @@ void connection::handle_read_frame(const lib::error_code& ec, template bool connection::initialize_processor() { - std::cout << "initialize_processor" << std::endl; + m_alog.write(log::alevel::devel,"initialize_processor"); // if it isn't a websocket handshake nothing to do. if (!processor::is_websocket_handshake(m_request)) { @@ -711,7 +726,8 @@ bool connection::initialize_processor() { int version = processor::get_websocket_version(m_request); if (version < 0) { - std::cout << "BAD REQUEST: cant determine version" << std::endl; + m_alog.write(log::alevel::devel, + "BAD REQUEST: can't determine version"); m_response.set_status(http::status_code::BAD_REQUEST); return false; } @@ -725,7 +741,8 @@ bool connection::initialize_processor() { // We don't have a processor for this version. Return bad request // with Sec-WebSocket-Version header filled with values we do accept - std::cout << "BAD REQUEST: no processor for version" << std::endl; + m_alog.write(log::alevel::devel, + "BAD REQUEST: no processor for version"); m_response.set_status(http::status_code::BAD_REQUEST); std::stringstream ss; @@ -743,11 +760,11 @@ bool connection::initialize_processor() { template bool connection::process_handshake_request() { - std::cout << "process handshake request" << std::endl; + m_alog.write(log::alevel::devel,"process handshake request"); if (!processor::is_websocket_handshake(m_request)) { // this is not a websocket handshake. Process as plain HTTP - std::cout << "HTTP REQUEST" << std::endl; + m_alog.write(log::alevel::devel,"HTTP REQUEST"); if (m_http_handler) { m_http_handler(m_connection_hdl); @@ -761,7 +778,8 @@ bool connection::process_handshake_request() { // Validate: make sure all required elements are present. if (ec){ // Not a valid handshake request - std::cout << "BAD REQUEST: (724) " << ec.message() << std::endl; + m_alog.write(log::alevel::devel, + "BAD REQUEST (724) "+ec.message()); m_response.set_status(http::status_code::BAD_REQUEST); return false; } @@ -774,7 +792,8 @@ bool connection::process_handshake_request() { if (neg_results.first) { // There was a fatal error in extension parsing that should result in // a failed connection attempt. - std::cout << "BAD REQUEST: (737) " << neg_results.first.message() << std::endl; + m_alog.write(log::alevel::devel, + "BAD REQUEST: (737) " + neg_results.first.message()); m_response.set_status(http::status_code::BAD_REQUEST); return false; } else { @@ -791,8 +810,8 @@ bool connection::process_handshake_request() { try { m_uri = m_processor->get_uri(m_request); } catch (const websocketpp::uri_exception& e) { - std::cout << "BAD REQUEST: uri failed to parse: " - << e.what() << std::endl; + m_alog.write(log::alevel::devel, + std::string("BAD REQUEST: uri failed to parse: ")+e.what()); m_response.set_status(http::status_code::BAD_REQUEST); return false; } @@ -806,15 +825,16 @@ bool connection::process_handshake_request() { ec = m_processor->process_handshake(m_request,m_response); if (ec) { - std::cout << "Processing error: " << ec - << "(" << ec.message() << ")" << std::endl; + std::stringstream s; + s << "Processing error: " << ec << "(" << ec.message() << ")"; + m_alog.write(log::alevel::devel,s.str()); m_response.set_status(http::status_code::INTERNAL_SERVER_ERROR); return false; } } else { // User application has rejected the handshake - std::cout << "USER REJECT" << std::endl; + m_alog.write(log::alevel::devel,"USER REJECT"); // Use Bad Request if the user handler did not provide a more // specific http response error code. @@ -835,13 +855,13 @@ void connection::handle_read(const lib::error_code& ec, size_t bytes_transferred) { if (ec) { - std::cout << "error in handle_read: " << ec << std::endl; + m_elog.write(log::elevel::rerror,"error in handle_read"+ec.message()); return; } // TODO: assert bytes_transferred < m_buf size. - std::cout << "connection handle_read" << std::endl; + m_alog.write(log::alevel::devel,"connection handle_read"); std::string foo(m_buf,bytes_transferred); @@ -860,7 +880,7 @@ void connection::handle_read(const lib::error_code& ec, template void connection::write(std::string msg) { - std::cout << "connection write" << std::endl; + m_alog.write(log::alevel::devel,"connection write"); transport_con_type::async_write( msg.c_str(), @@ -876,16 +896,17 @@ void connection::write(std::string msg) { template void connection::handle_write(const lib::error_code& ec) { if (ec) { - std::cout << "error in handle_write: " << ec << std::endl; + m_elog.write(log::elevel::rerror, + "error in handle_write: "+ec.message()); return; } - std::cout << "connection handle_write" << std::endl; + m_alog.write(log::alevel::devel,"connection handle_write"); } template void connection::send_http_response() { - std::cout << "send_http_response" << std::endl; + m_alog.write(log::alevel::devel,"connection send_http_response"); if (m_response.get_status_code() == http::status_code::UNINITIALIZED) { m_response.set_status(http::status_code::INTERNAL_SERVER_ERROR); @@ -906,8 +927,9 @@ void connection::send_http_response() { raw = m_response.raw(); } - std::cout << "Raw Handshake Response: " << std::endl; - std::cout << raw << std::endl; + if (m_alog.static_test(log::alevel::devel)) { + m_alog.write(log::alevel::devel,"Raw Handshake response:\n"+raw); + } // write raw bytes transport_con_type::async_write( @@ -925,7 +947,7 @@ template void connection::handle_send_http_response( const lib::error_code& ec) { - std::cout << "handle_send_http_response" << std::endl; + m_alog.write(log::alevel::devel,"handle_send_http_response"); this->atomic_state_check( istate::PROCESS_HTTP_REQUEST, @@ -933,7 +955,8 @@ void connection::handle_send_http_response( ); if (ec) { - std::cout << "error in handle_send_http_response: " << ec << std::endl; + m_elog.write(log::elevel::rerror, + "error in handle_send_http_response: "+ec.message()); this->terminate(); return; } @@ -945,12 +968,7 @@ void connection::handle_send_http_response( // the expected response and the connection can be closed. } else { // this was a websocket connection that ended in an error - std::cout << "Handshake ended with HTTP error: " - << m_response.get_status_code() << std::endl; - /*m_endpoint.m_elog->at(log::elevel::RERROR) - << "Handshake ended with HTTP error: " - << m_response.get_status_code() << " " - << m_response.get_status_msg() << log::endl;*/ + m_elog.write(log::elevel::rerror,"Handshake ended with HTTP error: "+m_response.get_status_code()); } this->terminate(); return; @@ -976,7 +994,7 @@ void connection::handle_send_http_response( template void connection::terminate() { - std::cout << "connection terminate" << std::endl; + m_alog.write(log::alevel::devel,"connection terminate"); transport_con_type::shutdown(); @@ -999,15 +1017,16 @@ void connection::terminate() { try { m_termination_handler(type::shared_from_this()); } catch (const std::exception& e) { - std::cout << "termination_handler call failed. Ignoring. Reason was: " - << e.what() << std::endl; + m_elog.write(log::elevel::warn, + std::string("termination_handler call failed. Reason was: ") + +e.what()); } } } template void connection::write_frame() { - std::cout << "connection write_frame" << std::endl; + m_alog.write(log::alevel::devel,"connection write_frame"); message_ptr msg; { @@ -1020,7 +1039,7 @@ void connection::write_frame() { msg = write_pop(); if (!msg) { - std::cout << "found empty message in write queue" << std::endl; + m_elog.write(log::elevel::warn,"found empty message in write queue"); throw; } } @@ -1031,11 +1050,17 @@ void connection::write_frame() { m_send_buffer.push_back(transport::buffer(header.c_str(),header.size())); m_send_buffer.push_back(transport::buffer(payload.c_str(),payload.size())); - std::cout << "Dispatching write with " << header.size() - << " header bytes and " << payload.size() - << " payload bytes" << std::endl; - std::cout << "frame is: " << utility::to_hex(header) - << utility::to_hex(payload) << std::endl; + if (m_alog.static_test(log::alevel::frame_header)) { + std::stringstream s; + s << "Dispatching write with " << header.size() + << " header bytes and " << payload.size() + << " payload bytes" << std::endl; + m_alog.write(log::alevel::frame_header,s.str()); + m_alog.write(log::alevel::frame_header,"Header: "+utility::to_hex(header)); + } + if (m_alog.static_test(log::alevel::frame_payload)) { + m_alog.write(log::alevel::frame_payload,"Payload: "+utility::to_hex(payload)); + } transport_con_type::async_write( m_send_buffer, @@ -1055,11 +1080,11 @@ void connection::handle_write_frame(bool terminate, m_send_buffer.clear(); if (ec) { - std::cout << "error in handle_write_frame: " << ec << std::endl; + m_elog.write(log::elevel::devel,"error in handle_write_frame: "+ec.message()); return; } - std::cout << "connection handle_write_frame" << std::endl; + m_alog.write(log::alevel::devel,"connection handle_write_frame"); if (terminate) { this->terminate(); @@ -1134,8 +1159,14 @@ template void connection::process_control_frame(typename config::message_type::ptr msg) { + m_alog.write(log::alevel::devel,"process_control_frame"); + frame::opcode::value op = msg->get_opcode(); lib::error_code ec; + + std::stringstream s; + s << "Control frame received with opcode " << op; + m_alog.write(log::alevel::control,s.str()); if (op == frame::opcode::PING) { bool pong = true; @@ -1147,8 +1178,8 @@ void connection::process_control_frame(typename if (pong) { this->pong(msg->get_payload(),ec); if (ec) { - std::cout << "Failed to send response pong: " - << ec.message() << std::endl; + m_elog.write(log::elevel::devel, + "Failed to send response pong: "+ec.message()); } } } else if (op == frame::opcode::PONG) { @@ -1156,16 +1187,27 @@ void connection::process_control_frame(typename m_pong_handler(m_connection_hdl, msg->get_payload()); } } else if (op == frame::opcode::CLOSE) { - std::cout << "Got close frame" << std::endl; + m_alog.write(log::alevel::devel,"got close frame"); // record close code and reason somewhere m_remote_close_code = close::extract_code(msg->get_payload(),ec); if (ec) { + std::stringstream s; if (config::drop_on_protocol_error) { + s << "Received invalid close code " << m_remote_close_code + << " dropping connection per config."; + m_elog.write(log::elevel::devel,s.str()); this->terminate(); } else { - send_close_ack(close::status::protocol_error, + s << "Received invalid close code " << m_remote_close_code + << " sending acknowledgement and closing"; + m_elog.write(log::elevel::devel,s.str()); + ec = send_close_ack(close::status::protocol_error, "Invalid close code"); + if (ec) { + m_elog.write(log::elevel::devel, + "send_close_ack error: "+ec.message()); + } } return; } @@ -1173,24 +1215,44 @@ void connection::process_control_frame(typename m_remote_close_reason = close::extract_reason(msg->get_payload(),ec); if (ec) { if (config::drop_on_protocol_error) { + m_elog.write(log::elevel::devel, + "Received invalid close reason. Dropping connection per config"); this->terminate(); } else { - send_close_ack(close::status::protocol_error, + m_elog.write(log::elevel::devel, + "Received invalid close reason. Sending acknowledgement and closing"); + ec = send_close_ack(close::status::protocol_error, "Invalid close reason"); + if (ec) { + m_elog.write(log::elevel::devel, + "send_close_ack error: "+ec.message()); + } } return; } if (m_state == session::state::OPEN) { - send_close_ack(); + std::stringstream s; + s << "Received close frame with code " << m_remote_close_code + << " and reason " << m_remote_close_reason; + m_alog.write(log::alevel::devel,s.str()); + + ec = send_close_ack(); + if (ec) { + m_elog.write(log::elevel::devel, + "send_close_ack error: "+ec.message()); + } } else if (m_state == session::state::CLOSING) { // ack of our close + m_alog.write(log::alevel::devel,"Got acknowledgement of close"); this->terminate(); } else { // spurious, ignore + m_elog.write(log::elevel::devel,"Got close frame in wrong state"); } } else { // got an invalid control opcode + m_elog.write(log::elevel::devel,"Got control frame with invalid opcode"); // initiate protocol error shutdown } } @@ -1206,6 +1268,7 @@ template lib::error_code connection::send_close_frame(close::status::value code, const std::string &reason, bool ack, bool terminal) { + m_alog.write(log::alevel::devel,"send_close_frame"); // If silent close is set, repsect it and blank out close information // Otherwise use whatever has been specified in the parameters. If // parameters specifies close::status::blank then determine what to do @@ -1213,22 +1276,33 @@ lib::error_code connection::send_close_frame(close::status::value code, // send blank info. If it is an ack then echo the close information from // the remote endpoint. if (config::silent_close) { + m_alog.write(log::alevel::devel,"closing silently"); m_local_close_code = close::status::no_status; m_local_close_reason = ""; } else if (code != close::status::blank) { + m_alog.write(log::alevel::devel,"closing with specified codes"); m_local_close_code = code; m_local_close_reason = reason; } else if (!ack) { + m_alog.write(log::alevel::devel,"closing with no status code"); m_local_close_code = close::status::no_status; m_local_close_reason = ""; } else if (m_remote_close_code == close::status::no_status) { + m_alog.write(log::alevel::devel, + "acknowledging a no-status close with normal code"); m_local_close_code = close::status::normal; m_local_close_reason = ""; } else { + m_alog.write(log::alevel::devel,"acknowledging with remote codes"); m_local_close_code = m_remote_close_code; m_local_close_reason = m_remote_close_reason; } - + + std::stringstream s; + s << "Closing with code: " << m_local_close_code << ", and reason: " + << m_local_close_reason; + m_alog.write(log::alevel::devel,s.str()); + message_ptr msg = m_msg_manager->get_message(); if (!msg) { return error::make_error_code(error::no_outgoing_buffers); @@ -1248,7 +1322,11 @@ lib::error_code connection::send_close_frame(close::status::value code, } // Concurrency review - bool needs_writing = write_push(msg); + bool needs_writing = false; + { + scoped_lock_type lock(m_write_lock); + needs_writing = write_push(msg); + } if (needs_writing) { transport_con_type::dispatch(lib::bind( @@ -1315,8 +1393,10 @@ bool connection::write_push(typename config::message_type::ptr msg) m_send_queue.push(msg); - std::cout << "write_push: message count: " << m_send_queue.size() - << " buffer size: " << m_send_buffer_size << std::endl; + std::stringstream s; + s << "write_push: message count: " << m_send_queue.size() + << " buffer size: " << m_send_buffer_size; + m_alog.write(log::alevel::devel,s.str()); return empty; } @@ -1329,8 +1409,10 @@ typename config::message_type::ptr connection::write_pop() m_send_buffer_size -= msg->get_payload().size(); m_send_queue.pop(); - std::cout << "write_pop: message count: " << m_send_queue.size() - << " buffer size: " << m_send_buffer_size << std::endl; + std::stringstream s; + s << "write_pop: message count: " << m_send_queue.size() + << " buffer size: " << m_send_buffer_size; + m_alog.write(log::alevel::devel,s.str()); return msg; } diff --git a/websocketpp/impl/endpoint_impl.hpp b/websocketpp/impl/endpoint_impl.hpp index 8959cf34cc..e99d0832d2 100644 --- a/websocketpp/impl/endpoint_impl.hpp +++ b/websocketpp/impl/endpoint_impl.hpp @@ -1,5 +1,5 @@ /* - * Copyright (c) 2012, Peter Thorson. All rights reserved. + * Copyright (c) 2013, Peter Thorson. All rights reserved. * * Redistribution and use in source and binary forms, with or without * modification, are permitted provided that the following conditions are met: @@ -33,7 +33,7 @@ namespace websocketpp { template typename endpoint::connection_ptr endpoint::create_connection() { - std::cout << "create_connection" << std::endl; + m_alog.write(log::alevel::devel,"create_connection"); //scoped_lock_type lock(m_state_lock); /*if (m_state == STOPPING || m_state == STOPPED) { @@ -41,7 +41,8 @@ endpoint::create_connection() { }*/ // Create a connection on the heap and manage it using a shared pointer - connection_ptr con(new connection_type(m_is_server,m_user_agent)); + connection_ptr con(new connection_type(m_is_server,m_user_agent,m_alog, + m_elog)); connection_weak_ptr w(con); @@ -88,8 +89,10 @@ endpoint::create_connection() { template void endpoint::remove_connection(connection_ptr con) { - std::cout << "remove_connection. New count: " << m_connections.size()-1 - << std::endl; + std::stringstream s; + s << "remove_connection. New count: " << m_connections.size()-1; + m_alog.write(log::alevel::devel,s.str()); + scoped_lock_type lock(m_mutex); // unregister the termination handler diff --git a/websocketpp/logger/basic.hpp b/websocketpp/logger/basic.hpp index e0d78b7f92..28faafffb4 100644 --- a/websocketpp/logger/basic.hpp +++ b/websocketpp/logger/basic.hpp @@ -41,11 +41,12 @@ */ #include +#include namespace websocketpp { -namespace logger { +namespace log { -struct error_names { +struct elevel { static const uint32_t none = 0x0; static const uint32_t devel = 0x1; static const uint32_t library = 0x2; @@ -75,7 +76,7 @@ struct error_names { } }; -struct access_names { +struct alevel { static const uint32_t none = 0x0; static const uint32_t connect = 0x1; static const uint32_t disconnect = 0x2; diff --git a/websocketpp/processors/hybi13.hpp b/websocketpp/processors/hybi13.hpp index 057aa629be..071229f2e8 100644 --- a/websocketpp/processors/hybi13.hpp +++ b/websocketpp/processors/hybi13.hpp @@ -1,5 +1,5 @@ /* - * Copyright (c) 2012, Peter Thorson. All rights reserved. + * Copyright (c) 2013, Peter Thorson. All rights reserved. * * Redistribution and use in source and binary forms, with or without * modification, are permitted provided that the following conditions are met: @@ -256,7 +256,7 @@ public: ec = lib::error_code(); - std::cout << "consume: " << utility::to_hex(buf,len) << std::endl; + //std::cout << "consume: " << utility::to_hex(buf,len) << std::endl; // Loop while we don't have a message ready and we still have bytes // left to process. @@ -546,7 +546,7 @@ public: std::copy(reason.begin(),reason.end(),payload.begin()+2); } - + return this->prepare_control(frame::opcode::CLOSE,payload,out); } protected: @@ -836,9 +836,9 @@ protected: } else { frame::extended_header e(payload.size()); out->set_header(frame::prepare_header(h,e)); - std::cout << "o: " << o.size() << std::endl; + //std::cout << "o: " << o.size() << std::endl; std::copy(payload.begin(),payload.end(),o.begin()); - std::cout << "o: " << o.size() << std::endl; + //std::cout << "o: " << o.size() << std::endl; } out->set_prepared(true); diff --git a/websocketpp/roles/server_endpoint.hpp b/websocketpp/roles/server_endpoint.hpp index 3fe95273e6..083a98e219 100644 --- a/websocketpp/roles/server_endpoint.hpp +++ b/websocketpp/roles/server_endpoint.hpp @@ -1,5 +1,5 @@ /* - * Copyright (c) 2012, Peter Thorson. All rights reserved. + * Copyright (c) 2013, Peter Thorson. All rights reserved. * * Redistribution and use in source and binary forms, with or without * modification, are permitted provided that the following conditions are met: @@ -68,7 +68,8 @@ public: explicit server() : endpoint_type(true) { - std::cout << "server constructor" << std::endl; + endpoint_type::m_alog.write(log::alevel::devel, + "server constructor"); } // return an initialized connection_ptr. Call start() on this object to @@ -99,13 +100,14 @@ public: if (!con) { // TODO: should this be considered a server fatal error? - std::cout << "handle_accept got an invalid handle back" - << std::endl; + endpoint_type::m_elog.write(log::elevel::warn, + "handle_accept got an invalid handle back"); } else { if (ec) { con->terminate(); - std::cout << "handle_accept: error: " << ec << std::endl; + endpoint_type::m_elog.write(log::elevel::rerror, + "handle_accept error: "+ec.message()); } else { con->start(); } diff --git a/websocketpp/transport/asio/connection.hpp b/websocketpp/transport/asio/connection.hpp index de942b9bc0..00679ffe51 100644 --- a/websocketpp/transport/asio/connection.hpp +++ b/websocketpp/transport/asio/connection.hpp @@ -38,7 +38,7 @@ #include #include -#include +#include #include namespace websocketpp { @@ -53,27 +53,33 @@ typedef lib::function tcp_init_handler; * Boost ASIO that works with the transport::asio::endpoint endpoint transport * component. */ -template -class connection : public socket { +template +class connection : public config::socket_type::socket_con_type { public: /// Type of this connection transport component - typedef connection type; + typedef connection type; /// Type of a shared pointer to this connection transport component typedef lib::shared_ptr ptr; /// Type of the socket connection component - typedef socket socket_con_type; + typedef typename config::socket_type::socket_con_type socket_con_type; /// Type of a shared pointer to the socket connection component typedef typename socket_con_type::ptr socket_con_ptr; + /// Type of this transport's access logging policy + typedef typename config::alog_type alog_type; + /// Type of this transport's error logging policy + typedef typename config::elog_type elog_type; /// Type of a pointer to the ASIO io_service being used typedef boost::asio::io_service* io_service_ptr; // generate and manage our own io_service - explicit connection(bool is_server) + explicit connection(bool is_server, alog_type& alog, elog_type& elog) : m_is_server(is_server) + , m_alog(alog) + , m_elog(elog) { - std::cout << "asio connection transport constructor" << std::endl; + m_alog.write(log::alevel::devel,"asio con transport constructor"); } bool is_secure() const { @@ -113,7 +119,7 @@ protected: * boost::asio components to the io_service */ void init(init_handler callback) { - std::cout << "asio connection init" << std::endl; + m_alog.write(log::alevel::devel,"asio connection init"); socket_con_type::init( lib::bind( @@ -141,11 +147,13 @@ protected: void async_read_at_least(size_t num_bytes, char *buf, size_t len, read_handler handler) { - std::cout << "asio async_read_at_least: " - << num_bytes << std::endl; + std::stringstream s; + s << "asio async_read_at_least: " << num_bytes; + m_alog.write(log::alevel::devel,s.str()); if (num_bytes > len) { - std::cout << "asio async_read_at_least error::invalid_num_bytes" << std::endl; + m_elog.write(log::elevel::devel, + "asio async_read_at_least error::invalid_num_bytes"); handler(make_error_code(error::invalid_num_bytes),size_t(0)); return; } @@ -169,13 +177,13 @@ protected: { // TODO: translate this better if (ec) { - std::cout << "asio async_read_at_least error::pass_through" - << "Original Error: " << ec - << " (" << ec.message() << ")" - << std::endl; + std::stringstream s; + s << "asio async_read_at_least error::pass_through" + << "Original Error: " << ec << " (" << ec.message() << ")"; + m_elog.write(log::elevel::devel,s.str()); handler(make_error_code(error::pass_through), bytes_transferred); } else { - std::cout << "asio async_read_at_least no error" << std::endl; + m_alog.write(log::alevel::devel,"asio async_read_at_least no error"); handler(lib::error_code(), bytes_transferred); } } @@ -264,7 +272,9 @@ protected: private: // static settings const bool m_is_server; - + alog_type& m_alog; + elog_type& m_elog; + // dynamic settings // transport state diff --git a/websocketpp/transport/asio/endpoint.hpp b/websocketpp/transport/asio/endpoint.hpp index 9af287171c..91a192055d 100644 --- a/websocketpp/transport/asio/endpoint.hpp +++ b/websocketpp/transport/asio/endpoint.hpp @@ -48,14 +48,21 @@ namespace asio { * transport::asio::endpoint impliments an endpoint transport component using * Boost ASIO. */ -template -class endpoint : public socket { +template +class endpoint : public config::socket_type { public: /// Type of this endpoint transport component - typedef endpoint type; - - /// Type of the socket endpoint component - typedef socket socket_type; + typedef endpoint type; + + /// Type of the concurrency policy + typedef typename config::concurrency_type concurrency_type; + /// Type of the socket policy + typedef typename config::socket_type socket_type; + /// Type of the error logging policy + typedef typename config::elog_type elog_type; + /// Type of the access logging policy + typedef typename config::alog_type alog_type; + /// Type of the socket connection component typedef typename socket_type::socket_con_type socket_con_type; /// Type of a shared pointer to the socket connection component @@ -63,7 +70,7 @@ public: /// Type of the connection transport component associated with this /// endpoint transport component - typedef asio::connection transport_con_type; + typedef asio::connection transport_con_type; /// Type of a shared pointer to the connection transport component /// associated with this endpoint transport component typedef typename transport_con_type::ptr transport_con_ptr; @@ -174,7 +181,8 @@ public: void listen(const boost::asio::ip::tcp::endpoint& e) { if (m_state != READY) { // TODO - std::cout << "asio::listen called from the wrong state" << std::endl; + m_elog->write(log::elevel::library, + "asio::listen called from the wrong state"); throw; } m_acceptor->open(e.protocol()); @@ -200,12 +208,12 @@ public: void async_accept(transport_con_ptr tcon, accept_handler callback) { if (m_state != LISTENING) { // TODO: throw invalid state - std::cout << "asio::async_accept called from the wrong state" - << std::endl; + m_elog->write(log::elevel::library, + "asio::async_accept called from the wrong state"); throw; } - std::cout << "call async accept" << std::endl; + m_alog->write(log::alevel::devel, "calling async accept"); // TEMP m_acceptor->async_accept( @@ -218,8 +226,6 @@ public: lib::placeholders::_1 ) ); - - std::cout << "done" << std::endl; } /// wraps the run method of the internal io_service object @@ -264,6 +270,21 @@ public: listen(*endpoint_iterator); } protected: + /// Initialize logging + /** + * The loggers are located in the main endpoint class. As such, the + * transport doesn't have direct access to them. This method is called + * by the endpoint constructor to allow shared logging from the transport + * component. These are raw pointers to member variables of the endpoint. + * In particular, they cannot be used in the transport constructor as they + * haven't been constructed yet, and cannot be used in the transport + * destructor as they will have been destroyed by then. + */ + void init_logging(elog_type* e, alog_type* a) { + m_elog = e; + m_alog = a; + } + void handle_accept(connection_hdl hdl, accept_handler callback, const boost::system::error_code& error) { @@ -283,14 +304,15 @@ protected: /// Initialize a connection /** - * init is called by an endpoint once for each newly created connection. It's - * purpose is to give the transport policy the chance to perform any transport - * specific initialization that couldn't be done via the default constructor. + * init is called by an endpoint once for each newly created connection. + * It's purpose is to give the transport policy the chance to perform any + * transport specific initialization that couldn't be done via the default + * constructor. * * @param tcon A pointer to the transport portion of the connection. */ void init(transport_con_ptr tcon) { - std::cout << "transport::asio::init" << std::endl; + m_alog->write(log::alevel::devel, "transport::asio::init"); // Initialize the connection socket component socket_type::init(lib::static_pointer_cast #include -#include +#include #include namespace websocketpp { namespace transport { namespace iostream { -template +template class connection { public: /// Type of this connection transport component - typedef connection type; + typedef connection type; /// Type of a shared pointer to this connection transport component typedef lib::shared_ptr ptr; - // TODO: clean up the rest of these types - typedef typename concurrency::scoped_lock_type scoped_lock_type; - typedef typename concurrency::mutex_type mutex_type; + /// transport concurrency policy + typedef typename config::concurrency_type concurrency_type; + /// Type of this transport's access logging policy + typedef typename config::alog_type alog_type; + /// Type of this transport's error logging policy + typedef typename config::elog_type elog_type; + + // Concurrency policy types + typedef typename concurrency_type::scoped_lock_type scoped_lock_type; + typedef typename concurrency_type::mutex_type mutex_type; - explicit connection(bool is_server) + explicit connection(bool is_server, alog_type& alog, elog_type& elog) : m_reading(false) , m_is_server(is_server) + , m_alog(alog) + , m_elog(elog) { - std::cout << "iostream connection transport constructor" << std::endl; + m_alog.write(log::alevel::devel,"iostream con transport constructor"); } void register_ostream(std::ostream* o) { @@ -80,7 +89,7 @@ public: } protected: void init(init_handler callback) { - std::cout << "iostream connection init" << std::endl; + m_alog.write(log::alevel::devel,"iostream connection init"); callback(lib::error_code()); } @@ -95,7 +104,9 @@ protected: void async_read_at_least(size_t num_bytes, char *buf, size_t len, read_handler handler) { - std::cout << "iostream_con async_read_at_least: " << num_bytes << std::endl; + std::stringstream s; + s << "iostream_con async_read_at_least: " << num_bytes; + m_alog.write(log::alevel::devel,s.str()); if (num_bytes > len) { handler(make_error_code(error::invalid_num_bytes),size_t(0)); @@ -116,7 +127,7 @@ protected: } void async_write(const char* buf, size_t len, write_handler handler) { - std::cout << "iostream_con async_write" << std::endl; + m_alog.write(log::alevel::devel,"iostream_con async_write"); // TODO: lock transport state? if (!output_stream) { @@ -138,7 +149,7 @@ protected: * TODO: unit tests */ void async_write(const std::vector& bufs, write_handler handler) { - std::cout << "iostream_con async_write buffer list" << std::endl; + m_alog.write(log::alevel::devel,"iostream_con async_write buffer list"); // TODO: lock transport state? if (!output_stream) { @@ -176,18 +187,18 @@ protected: } private: void read(std::istream &in) { - std::cout << "iostream_con read" << std::endl; + m_alog.write(log::alevel::devel,"iostream_con read"); while (in.good()) { if (!m_reading) { - std::cout << "write while not reading" << std::endl; + m_elog.write(log::elevel::devel,"write while not reading"); break; } in.read(m_buf,m_len-m_cursor); if (in.gcount() == 0) { - std::cout << "read zero bytes" << std::endl; + m_elog.write(log::elevel::devel,"read zero bytes"); break; } @@ -219,6 +230,8 @@ private: bool m_reading; const bool m_is_server; + alog_type& m_alog; + elog_type& m_elog; // This lock ensures that only one thread can edit read data for this // connection. This is a very coarse lock that is basically locked all the diff --git a/websocketpp/transport/iostream/endpoint.hpp b/websocketpp/transport/iostream/endpoint.hpp index 3ad92933de..ee34b868f3 100644 --- a/websocketpp/transport/iostream/endpoint.hpp +++ b/websocketpp/transport/iostream/endpoint.hpp @@ -1,5 +1,5 @@ /* - * Copyright (c) 2012, Peter Thorson. All rights reserved. + * Copyright (c) 2013, Peter Thorson. All rights reserved. * * Redistribution and use in source and binary forms, with or without * modification, are permitted provided that the following conditions are met: @@ -29,6 +29,7 @@ #define WEBSOCKETPP_TRANSPORT_IOSTREAM_HPP #include +#include #include @@ -38,17 +39,24 @@ namespace websocketpp { namespace transport { namespace iostream { -template +template class endpoint { public: /// Type of this endpoint transport component typedef endpoint type; /// Type of a pointer to this endpoint transport component typedef lib::shared_ptr ptr; + + /// Type of this endpoint's concurrency policy + typedef typename config::concurrency_type concurrency_type; + /// Type of this endpoint's error logging policy + typedef typename config::elog_type elog_type; + /// Type of this endpoint's access logging policy + typedef typename config::alog_type alog_type; /// Type of this endpoint transport component's associated connection /// transport component. - typedef iostream::connection transport_con_type; + typedef iostream::connection transport_con_type; /// Type of a shared pointer to this endpoint transport component's /// associated connection transport component typedef typename transport_con_type::ptr transport_con_ptr; @@ -60,14 +68,32 @@ public: } void register_ostream(std::ostream* o) { + m_alog->write(log::alevel::devel,"register_ostream"); output_stream = o; } protected: + /// Initialize logging + /** + * The loggers are located in the main endpoint class. As such, the + * transport doesn't have direct access to them. This method is called + * by the endpoint constructor to allow shared logging from the transport + * component. These are raw pointers to member variables of the endpoint. + * In particular, they cannot be used in the transport constructor as they + * haven't been constructed yet, and cannot be used in the transport + * destructor as they will have been destroyed by then. + */ + void init_logging(elog_type* e, alog_type* a) { + m_elog = e; + m_alog = a; + } + void init(transport_con_ptr tcon) { tcon->register_ostream(output_stream); } private: std::ostream* output_stream; + elog_type* m_elog; + alog_type* m_alog; };