From 0688b7eb6489e6ea0bf9f6e724c1baa3b5359a41 Mon Sep 17 00:00:00 2001 From: Michael Vandeberg Date: Wed, 25 Jan 2017 10:16:02 -0500 Subject: [PATCH 1/2] Time execution of rpc API call and log long executing calls. #9 --- src/rpc/websocket_api.cpp | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/src/rpc/websocket_api.cpp b/src/rpc/websocket_api.cpp index 0ff9304..efbb1d1 100644 --- a/src/rpc/websocket_api.cpp +++ b/src/rpc/websocket_api.cpp @@ -98,7 +98,15 @@ std::string websocket_api_connection::on_message( { try { + auto start = time_point::now(); auto result = _rpc_state.local_call( call.method, call.params ); + auto end = time_point::now(); + + if( end - start > fc::seconds( 1 ) ) + elog( "API call execution time limit exceeded.", ("method",call.method)("params",call.params)("time", end - start) ); + else if( end - start > fc::milliseconds( 750 ) ) + wlog( "API call execution time nearing limit.", ("method",call.method)("params",call.params)("time", end - start) ); + if( call.id ) { auto reply = fc::json::to_string( response( *call.id, result ) ); From c1a0dca92f18c504c444da706b722c46c7770206 Mon Sep 17 00:00:00 2001 From: Michael Vandeberg Date: Wed, 25 Jan 2017 11:16:52 -0500 Subject: [PATCH 2/2] Refactor to use cmake build options #9 --- CMakeLists.txt | 14 ++++++++++++++ src/rpc/websocket_api.cpp | 10 ++++++++-- 2 files changed, 22 insertions(+), 2 deletions(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index b6d7774..3291c9a 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -341,6 +341,20 @@ SET(CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -DWEBSOCKETPP_STRICT_MASKING") SET(CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -DBOOST_ASIO_HAS_STD_CHRONO") +OPTION( LOG_LONG_API "Log long API calls over websocket (ON OR OFF)" ON ) +MESSAGE( STATUS "LOG_LONG_API: ${LOG_LONG_API}" ) +if( LOG_LONG_API ) + SET( LOG_LONG_API_MAX_MS 1000 CACHE STRING "Max API execution time in ms" ) + SET( LOG_LONG_API_WARN_MS 750 CACHE STRING "API execution time in ms at which to warn" ) + MESSAGE( STATUS " " ) + MESSAGE( STATUS " LOGGING LONG API CALLS" ) + MESSAGE( STATUS " MAX MS: ${LOG_LONG_API_MAX_MS}" ) + MESSAGE( STATUS " WARN MS: ${LOG_LONG_API_WARN_MS}" ) + MESSAGE( STATUS " " ) + SET( CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -DLOG_LONG_API -DLOG_LONG_API_MAX_MS=${LOG_LONG_API_MAX_MS} -DLOG_LONG_API_WARN_MS=${LOG_LONG_API_WARN_MS}" ) + SET( CMAKE_C_FLAGS "${CMAKE_C_FLAGS} -DLOG_LONG_API -DLOG_LONG_API_MAX_MS=${LOG_LONG_API_MAX_MS} -DLOG_LONG_API_WARN_MS=${LOG_LONG_API_WARN_MS}" ) +endif() + target_include_directories(fc PUBLIC ${CMAKE_CURRENT_SOURCE_DIR}/include ${Boost_INCLUDE_DIR} diff --git a/src/rpc/websocket_api.cpp b/src/rpc/websocket_api.cpp index efbb1d1..8843f9e 100644 --- a/src/rpc/websocket_api.cpp +++ b/src/rpc/websocket_api.cpp @@ -98,14 +98,20 @@ std::string websocket_api_connection::on_message( { try { +#ifdef LOG_LONG_API auto start = time_point::now(); +#endif + auto result = _rpc_state.local_call( call.method, call.params ); + +#ifdef LOG_LONG_API auto end = time_point::now(); - if( end - start > fc::seconds( 1 ) ) + if( end - start > fc::milliseconds( LOG_LONG_API_MAX_MS ) ) elog( "API call execution time limit exceeded.", ("method",call.method)("params",call.params)("time", end - start) ); - else if( end - start > fc::milliseconds( 750 ) ) + else if( end - start > fc::milliseconds( LOG_LONG_API_WARN_MS ) ) wlog( "API call execution time nearing limit.", ("method",call.method)("params",call.params)("time", end - start) ); +#endif if( call.id ) {