From 32a9e12f6216db90332203eb79fd465cd8ae7838 Mon Sep 17 00:00:00 2001 From: tt2468 Date: Sat, 20 Nov 2021 01:50:49 -0800 Subject: [PATCH] Base: Logging improvements Use blog_debug() in place of almost all debug logging messages, and change some log levels to be less verbose. --- src/Config.h | 2 +- src/WebSocketApi.cpp | 24 +++++++------------ src/eventhandler/EventHandler.cpp | 20 +++++++--------- src/obs-websocket.cpp | 2 +- src/utils/Obs.cpp | 2 -- src/websocketserver/WebSocketServer.cpp | 15 ++++-------- src/websocketserver/WebSocketServer.h | 1 - .../WebSocketServer_Protocol.cpp | 2 +- ...WebSocketServer_RequestBatchProcessing.cpp | 12 ++++------ 9 files changed, 28 insertions(+), 52 deletions(-) diff --git a/src/Config.h b/src/Config.h index 9af0b499..16851415 100644 --- a/src/Config.h +++ b/src/Config.h @@ -39,7 +39,7 @@ class Config { bool ServerEnabled; uint16_t ServerPort; std::atomic DebugEnabled; - std::atomic AlertsEnabled; + bool AlertsEnabled; bool AuthRequired; QString ServerPassword; diff --git a/src/WebSocketApi.cpp b/src/WebSocketApi.cpp index 5e5be3b6..e4a4a4f4 100644 --- a/src/WebSocketApi.cpp +++ b/src/WebSocketApi.cpp @@ -19,8 +19,7 @@ WebSocketApi::Vendor *get_vendor(calldata_t *cd) WebSocketApi::WebSocketApi(EventCallback cb) : _eventCallback(cb) { - if (IsDebugEnabled()) - blog(LOG_INFO, "[WebSocketApi::WebSocketApi] Setting up..."); + blog_debug("[WebSocketApi::WebSocketApi] Setting up..."); _procHandler = proc_handler_create(); @@ -34,25 +33,21 @@ WebSocketApi::WebSocketApi(EventCallback cb) : proc_handler_add(ph, "bool obs_websocket_api_get_ph(out ptr ph)", &get_ph_cb, this); - if (IsDebugEnabled()) - blog(LOG_INFO, "[WebSocketApi::WebSocketApi] Finished."); + blog_debug("[WebSocketApi::WebSocketApi] Finished."); } WebSocketApi::~WebSocketApi() { - if (IsDebugEnabled()) - blog(LOG_INFO, "[WebSocketApi::~WebSocketApi] Shutting down..."); + blog_debug("[WebSocketApi::~WebSocketApi] Shutting down..."); proc_handler_destroy(_procHandler); for (auto vendor : _vendors) { - if (IsDebugEnabled()) - blog(LOG_INFO, "[WebSocketApi::~WebSocketApi] Deleting vendor: %s", vendor.first.c_str()); + blog_debug("[WebSocketApi::~WebSocketApi] Deleting vendor: %s", vendor.first.c_str()); delete vendor.second; } - if (IsDebugEnabled()) - blog(LOG_INFO, "[WebSocketApi::~WebSocketApi] Finished."); + blog_debug("[WebSocketApi::~WebSocketApi] Finished."); } enum WebSocketApi::RequestReturnCode WebSocketApi::PerformVendorRequest(std::string vendorName, std::string requestType, obs_data_t *requestData, obs_data_t *responseData) @@ -112,8 +107,7 @@ void WebSocketApi::vendor_register_cb(void *priv_data, calldata_t *cd) c->_vendors[vendorName] = v; - if (IsDebugEnabled()) - blog(LOG_INFO, "[WebSocketApi::vendor_register_cb] [vendorName: %s] Registered new vendor.", v->_name.c_str()); + blog_debug("[WebSocketApi::vendor_register_cb] [vendorName: %s] Registered new vendor.", v->_name.c_str()); calldata_set_ptr(cd, "vendor", static_cast(v)); @@ -151,8 +145,7 @@ void WebSocketApi::vendor_request_register_cb(void *priv_data, calldata_t *cd) v->_requests[requestType] = *cb; - if (IsDebugEnabled()) - blog(LOG_INFO, "[WebSocketApi::vendor_request_register_cb] [vendorName: %s] Registered new vendor request: %s", v->_name.c_str(), requestType); + blog_debug("[WebSocketApi::vendor_request_register_cb] [vendorName: %s] Registered new vendor request: %s", v->_name.c_str(), requestType); RETURN_SUCCESS(); } @@ -180,8 +173,7 @@ void WebSocketApi::vendor_request_unregister_cb(void *priv_data, calldata_t *cd) v->_requests.erase(requestType); - if (IsDebugEnabled()) - blog(LOG_INFO, "[WebSocketApi::vendor_request_unregister_cb] [vendorName: %s] Unregistered vendor request: %s", v->_name.c_str(), requestType); + blog_debug("[WebSocketApi::vendor_request_unregister_cb] [vendorName: %s] Unregistered vendor request: %s", v->_name.c_str(), requestType); RETURN_SUCCESS(); } diff --git a/src/eventhandler/EventHandler.cpp b/src/eventhandler/EventHandler.cpp index 4e28f911..808deb94 100644 --- a/src/eventhandler/EventHandler.cpp +++ b/src/eventhandler/EventHandler.cpp @@ -26,8 +26,7 @@ EventHandler::EventHandler() : _inputShowStateChangedRef(0), _sceneItemTransformChangedRef(0) { - if (IsDebugEnabled()) - blog(LOG_INFO, "[EventHandler::EventHandler] Setting up..."); + blog_debug("[EventHandler::EventHandler] Setting up..."); obs_frontend_add_event_callback(OnFrontendEvent, this); @@ -41,14 +40,12 @@ EventHandler::EventHandler() : blog(LOG_ERROR, "[EventHandler::EventHandler] Unable to get libobs signal handler!"); } - if (IsDebugEnabled()) - blog(LOG_INFO, "[EventHandler::EventHandler] Finished."); + blog_debug("[EventHandler::EventHandler] Finished."); } EventHandler::~EventHandler() { - if (IsDebugEnabled()) - blog(LOG_INFO, "[EventHandler::~EventHandler] Shutting down..."); + blog_debug("[EventHandler::~EventHandler] Shutting down..."); obs_frontend_remove_event_callback(OnFrontendEvent, this); @@ -62,8 +59,7 @@ EventHandler::~EventHandler() blog(LOG_ERROR, "[EventHandler::~EventHandler] Unable to get libobs signal handler!"); } - if (IsDebugEnabled()) - blog(LOG_INFO, "[EventHandler::~EventHandler] Finished."); + blog_debug("[EventHandler::~EventHandler] Finished."); } void EventHandler::SetBroadcastCallback(EventHandler::BroadcastCallback cb) @@ -197,7 +193,7 @@ void EventHandler::OnFrontendEvent(enum obs_frontend_event event, void *private_ if (!eventHandler->_obsLoaded.load()) { if (event == OBS_FRONTEND_EVENT_FINISHED_LOADING) { - blog(LOG_INFO, "[EventHandler::OnFrontendEvent] OBS has finished loading. Connecting final handlers and enabling events..."); + blog_debug("[EventHandler::OnFrontendEvent] OBS has finished loading. Connecting final handlers and enabling events..."); // Connect source signals and enable events only after OBS has fully loaded (to reduce extra logging). eventHandler->_obsLoaded.store(true); @@ -216,7 +212,7 @@ void EventHandler::OnFrontendEvent(enum obs_frontend_event event, void *private_ return true; }, private_data); - blog(LOG_INFO, "[EventHandler::OnFrontendEvent] Finished."); + blog_debug("[EventHandler::OnFrontendEvent] Finished."); if (eventHandler->_obsLoadedCallback) eventHandler->_obsLoadedCallback(); @@ -230,7 +226,7 @@ void EventHandler::OnFrontendEvent(enum obs_frontend_event event, void *private_ case OBS_FRONTEND_EVENT_EXIT: eventHandler->HandleExitStarted(); - blog(LOG_INFO, "[EventHandler::OnFrontendEvent] OBS is unloading. Disabling events..."); + blog_debug("[EventHandler::OnFrontendEvent] OBS is unloading. Disabling events..."); // Disconnect source signals and disable events when OBS starts unloading (to reduce extra logging). eventHandler->_obsLoaded.store(false); @@ -249,7 +245,7 @@ void EventHandler::OnFrontendEvent(enum obs_frontend_event event, void *private_ return true; }, private_data); - blog(LOG_INFO, "[EventHandler::OnFrontendEvent] Finished."); + blog_debug("[EventHandler::OnFrontendEvent] Finished."); break; case OBS_FRONTEND_EVENT_STUDIO_MODE_ENABLED: diff --git a/src/obs-websocket.cpp b/src/obs-websocket.cpp index cf3b6400..830983ce 100644 --- a/src/obs-websocket.cpp +++ b/src/obs-websocket.cpp @@ -91,7 +91,7 @@ void obs_module_unload() blog(LOG_INFO, "[obs_module_unload] Shutting down..."); if (_webSocketServer->IsListening()) { - blog(LOG_INFO, "[obs_module_unload] WebSocket server is running. Stopping..."); + blog_debug("[obs_module_unload] WebSocket server is running. Stopping..."); _webSocketServer->Stop(); } _webSocketServer.reset(); diff --git a/src/utils/Obs.cpp b/src/utils/Obs.cpp index e3590246..b3a21a62 100644 --- a/src/utils/Obs.cpp +++ b/src/utils/Obs.cpp @@ -306,8 +306,6 @@ std::vector Utils::Obs::ListHelper::GetSceneItemList(obs_scene_t *scene, b item["sceneItemId"] = obs_sceneitem_get_id(sceneItem); // Should be slightly faster than calling obs_sceneitem_get_order_position() item["sceneItemIndex"] = enumData->first.size(); - //OBSSource itemSourcee = obs_sceneitem_get_source(sceneItem); - //blog(LOG_INFO, "source name: %s | item refs: %lu", obs_source_get_name(itemSourcee), obs_source_get_sceneitem_count(itemSourcee)); if (!enumData->second) { OBSSource itemSource = obs_sceneitem_get_source(sceneItem); item["sourceName"] = obs_source_get_name(itemSource); diff --git a/src/websocketserver/WebSocketServer.cpp b/src/websocketserver/WebSocketServer.cpp index 3da190ac..be288b75 100644 --- a/src/websocketserver/WebSocketServer.cpp +++ b/src/websocketserver/WebSocketServer.cpp @@ -114,13 +114,12 @@ void WebSocketServer::Start() _serverPort = conf->ServerPort; _serverPassword = conf->ServerPassword; - _debugEnabled = conf->DebugEnabled; AuthenticationRequired = conf->AuthRequired; AuthenticationSalt = Utils::Crypto::GenerateSalt(); AuthenticationSecret = Utils::Crypto::GenerateSecret(conf->ServerPassword.toStdString(), AuthenticationSalt); // Set log levels if debug is enabled - if (_debugEnabled) { + if (IsDebugEnabled()) { _server.get_alog().set_channels(websocketpp::log::alevel::all); _server.get_alog().clear_channels(websocketpp::log::alevel::frame_header | websocketpp::log::alevel::frame_payload | websocketpp::log::alevel::control); _server.get_elog().set_channels(websocketpp::log::elevel::all); @@ -232,8 +231,7 @@ void WebSocketServer::onObsLoaded() } if (conf->ServerEnabled) { - if (conf->DebugEnabled) - blog(LOG_INFO, "[WebSocketServer::onObsLoaded] Server is enabled in configuration. Starting server..."); + blog(LOG_INFO, "[WebSocketServer::onObsLoaded] WebSocket server is enabled, starting..."); Start(); } } @@ -307,8 +305,7 @@ void WebSocketServer::onOpen(websocketpp::connection_hdl hdl) // Log connection blog(LOG_INFO, "[WebSocketServer::onOpen] New WebSocket client has connected from %s", session->RemoteAddress().c_str()); - if (_debugEnabled) - blog(LOG_INFO, "[WebSocketServer::onOpen] Sending Op 0 (Hello) message:\n%s", helloMessage.dump(2).c_str()); + blog_debug("[WebSocketServer::onOpen] Sending Op 0 (Hello) message:\n%s", helloMessage.dump(2).c_str()); // Send object to client websocketpp::lib::error_code errorCode; @@ -426,8 +423,7 @@ void WebSocketServer::onMessage(websocketpp::connection_hdl hdl, websocketpp::se } } - if (_debugEnabled) - blog(LOG_INFO, "[WebSocketServer::onMessage] Incoming message (decoded):\n%s", incomingMessage.dump(2).c_str()); + blog_debug("[WebSocketServer::onMessage] Incoming message (decoded):\n%s", incomingMessage.dump(2).c_str()); ProcessResult ret; @@ -480,8 +476,7 @@ skipProcessing: } session->IncrementOutgoingMessages(); - if (_debugEnabled) - blog(LOG_INFO, "[WebSocketServer::onMessage] Outgoing message:\n%s", ret.result.dump(2).c_str()); + blog_debug("[WebSocketServer::onMessage] Outgoing message:\n%s", ret.result.dump(2).c_str()); if (errorCode) blog(LOG_WARNING, "[WebSocketServer::onMessage] Sending message to client failed: %s", errorCode.message().c_str()); diff --git a/src/websocketserver/WebSocketServer.h b/src/websocketserver/WebSocketServer.h index 651353c6..d8f46021 100644 --- a/src/websocketserver/WebSocketServer.h +++ b/src/websocketserver/WebSocketServer.h @@ -132,5 +132,4 @@ class WebSocketServer : QObject std::map> _sessions; uint16_t _serverPort; QString _serverPassword; - bool _debugEnabled; }; diff --git a/src/websocketserver/WebSocketServer_Protocol.cpp b/src/websocketserver/WebSocketServer_Protocol.cpp index 3eb57d01..33df7b0e 100644 --- a/src/websocketserver/WebSocketServer_Protocol.cpp +++ b/src/websocketserver/WebSocketServer_Protocol.cpp @@ -354,7 +354,7 @@ void WebSocketServer::BroadcastEvent(uint64_t requiredIntent, std::string eventT } } lock.unlock(); - if (_debugEnabled && (EventSubscription::All & requiredIntent) != 0) // Don't log high volume events + if (IsDebugEnabled() && (EventSubscription::All & requiredIntent) != 0) // Don't log high volume events blog(LOG_INFO, "[WebSocketServer::BroadcastEvent] Outgoing event:\n%s", eventMessage.dump(2).c_str()); })); } diff --git a/src/websocketserver/WebSocketServer_RequestBatchProcessing.cpp b/src/websocketserver/WebSocketServer_RequestBatchProcessing.cpp index 964e4476..dee8e156 100644 --- a/src/websocketserver/WebSocketServer_RequestBatchProcessing.cpp +++ b/src/websocketserver/WebSocketServer_RequestBatchProcessing.cpp @@ -81,14 +81,12 @@ bool PreProcessVariables(const json &variables, const json &inputVariables, json std::string key = it.key(); if (!variables.contains(key)) { - if (IsDebugEnabled()) - blog(LOG_WARNING, "[WebSocketServer::ProcessRequestBatch] inputVariables requested variable `%s`, but it does not exist. Skipping!", key.c_str()); + blog_debug("[WebSocketServer::ProcessRequestBatch] inputVariables requested variable `%s`, but it does not exist. Skipping!", key.c_str()); continue; } if (!it.value().is_string()) { - if (IsDebugEnabled()) - blog(LOG_WARNING, "[WebSocketServer::ProcessRequestBatch] Value of item `%s` in inputVariables is not a string. Skipping!", key.c_str()); + blog_debug("[WebSocketServer::ProcessRequestBatch] Value of item `%s` in inputVariables is not a string. Skipping!", key.c_str()); continue; } @@ -108,14 +106,12 @@ void PostProcessVariables(json &variables, const json &outputVariables, const js std::string key = it.key(); if (!responseData.contains(key)) { - if (IsDebugEnabled()) - blog(LOG_WARNING, "[WebSocketServer::ProcessRequestBatch] outputVariables requested responseData item `%s`, but it does not exist. Skipping!", key.c_str()); + blog_debug("[WebSocketServer::ProcessRequestBatch] outputVariables requested responseData item `%s`, but it does not exist. Skipping!", key.c_str()); continue; } if (!it.value().is_string()) { - if (IsDebugEnabled()) - blog(LOG_WARNING, "[WebSocketServer::ProcessRequestBatch] Value of item `%s` in outputVariables is not a string. Skipping!", key.c_str()); + blog_debug("[WebSocketServer::ProcessRequestBatch] Value of item `%s` in outputVariables is not a string. Skipping!", key.c_str()); continue; }