diff --git a/xspdApp/Db/ADXSPD.template b/xspdApp/Db/ADXSPD.template index e528b96..130b9c4 100644 --- a/xspdApp/Db/ADXSPD.template +++ b/xspdApp/Db/ADXSPD.template @@ -20,6 +20,7 @@ ################################################################## include "ADBase.template" +include "NDFile.template" # ADBase record overrides @@ -620,6 +621,26 @@ record(ai, "$(P)$(R)BloscNumThreads_RBV"){ field(SCAN, "I/O Intr") } +# Log files are written to FilePath; stdout is used if FilePath is empty +record(bo, "$(P)$(R)LogRequests"){ + field(DESC, "Log HTTP requests sent to XSPD") + field(DTYP, "asynInt32") + field(OUT, "@asyn($(PORT),$(ADDR),$(TIMEOUT))XSPD_LOG_REQUESTS") + field(ZNAM, "Disabled") + field(ONAM, "Enabled") + field(VAL, "0") + field(PINI, "NO") +} + +record(bi, "$(P)$(R)LogRequests_RBV"){ + field(DESC, "Log HTTP requests readback") + field(DTYP, "asynInt32") + field(INP, "@asyn($(PORT),$(ADDR),$(TIMEOUT))XSPD_LOG_REQUESTS") + field(ZNAM, "Disabled") + field(ONAM, "Enabled") + field(SCAN, "I/O Intr") +} + # Disable any ADBase records we don't want to use record(mbbo, "$(P)$(R)DataType") diff --git a/xspdApp/Db/ADXSPD_settings.req b/xspdApp/Db/ADXSPD_settings.req index b263577..8f053ca 100644 --- a/xspdApp/Db/ADXSPD_settings.req +++ b/xspdApp/Db/ADXSPD_settings.req @@ -1 +1,2 @@ file "ADBase_settings.req", P=$(P), R=$(R) +file "NDFile_settings.req", P=$(P), R=$(R) diff --git a/xspdApp/op/bob/ADXSPD.bob b/xspdApp/op/bob/ADXSPD.bob index 48429a6..e3be1e7 100644 --- a/xspdApp/op/bob/ADXSPD.bob +++ b/xspdApp/op/bob/ADXSPD.bob @@ -1,5 +1,5 @@ - + ADXSPD Control - $(P) @@ -17,9 +17,9 @@ Monitor 750 - 612 + 602 375 - 144 + 120 @@ -36,9 +36,9 @@ Label_22 Timeout (s) - 34 - 49 - 110 + 6 + 60 + 125 @@ -52,8 +52,8 @@ TextUpdate_14 $(P)$(R)MonitorInterval_RBV - 229 - 49 + 251 + 60 80 @@ -71,9 +71,8 @@ TextEntry_6 $(P)$(R)MonitorInterval - 161 - 49 - 60 + 140 + 60 @@ -87,7 +86,8 @@ Label_45 Monitor mode 6 - 24 + 10 + 125 @@ -101,8 +101,8 @@ ComboBox_15 $(P)$(R)MonitorMode - 118 - 24 + 140 + 10 20 @@ -116,8 +116,59 @@ TextUpdate_33 $(P)$(R)MonitorMode_RBV - 234 - 24 + 251 + 10 + 80 + + + + + + + + + + + + + + + Label_46 + Log Requests + 6 + 35 + 125 + + + + + + + + + 2 + + + ComboBox_18 + $(P)$(R)LogRequests + 140 + 35 + 20 + + + + + + + + + + + TextUpdate_34 + $(P)$(R)LogRequests_RBV + 251 + 35 + 80 @@ -1080,7 +1131,7 @@ Shutter - 675 + 696 375 166 @@ -1337,7 +1388,7 @@ Detector Status - 475 + 485 375 @@ -1961,7 +2012,7 @@ Plugins - 375 + 385 375 100 @@ -3707,7 +3758,7 @@ Attributes 750 - 756 + 722 375 120 diff --git a/xspdApp/src/ADXSPD.cpp b/xspdApp/src/ADXSPD.cpp index f5d7e7d..169e73c 100644 --- a/xspdApp/src/ADXSPD.cpp +++ b/xspdApp/src/ADXSPD.cpp @@ -199,6 +199,47 @@ asynStatus ADXSPD::acquireStop() { return asynSuccess; } +/** + * @brief Enables or disables logging of HTTP requests sent to XSPD. + * + * Logs are written to /, or /xspd_requests.log if FileName is empty. + * If FilePath is empty, logs are written to stdout. + * + * @param enable Whether to enable request logging + * @throws runtime_error if the file path does not exist or the log file cannot be opened + */ +void ADXSPD::setRequestLogging(bool enable) { + if (!enable) { + this->pApi->DisableRequestLogging(); + setStringParam(NDFullFileName, ""); + return; + } + + char filePath[MAX_FILENAME_LEN]; + char fileName[MAX_FILENAME_LEN]; + getStringParam(NDFilePath, sizeof(filePath), filePath); + + if (strlen(filePath) == 0) { + this->pApi->EnableRequestLogging(); + setStringParam(NDFullFileName, ""); + INFO("Logging XSPD requests to stdout"); + return; + } + + if (this->checkPath() != asynSuccess) + throw runtime_error("File path " + string(filePath) + " does not exist"); + + // checkPath() normalizes the path to include a trailing delimiter + getStringParam(NDFilePath, sizeof(filePath), filePath); + getStringParam(NDFileName, sizeof(fileName), fileName); + string logFilePath = + string(filePath) + (strlen(fileName) > 0 ? string(fileName) : "xspd_requests.log"); + + this->pApi->EnableRequestLogging(logFilePath); + setStringParam(NDFullFileName, logFilePath.c_str()); + INFO_ARGS("Logging XSPD requests to %s", logFilePath.c_str()); +} + /** * @brief Subtracts two frames element-wise with floor at 0 * @@ -788,6 +829,8 @@ asynStatus ADXSPD::writeInt32(asynUser* pasynUser, epicsInt32 value) { if (value < ADXSPD_MIN_STATUS_POLL_INTERVAL) { actualValue = ADXSPD_MIN_STATUS_POLL_INTERVAL; } + } else if (function == ADXSPD_LogRequests) { + this->setRequestLogging(value != 0); } setIntegerParam(function, actualValue); @@ -890,6 +933,39 @@ asynStatus ADXSPD::writeFloat64(asynUser* pasynUser, epicsFloat64 value) { } } +/** + * @brief Override of asynNDArrayDriver::writeOctet. Re-opens the request log if the file + * path or name changes while request logging is enabled. + * + * @param pasynUser asyn client who requests a write + * @param value string value to write + * @param nChars number of characters to write + * @param nActual number of characters actually written + * @return asynStatus success if write was successful, else failure + */ +asynStatus ADXSPD::writeOctet(asynUser* pasynUser, const char* value, size_t nChars, + size_t* nActual) { + int function = pasynUser->reason; + asynStatus status = ADDriver::writeOctet(pasynUser, value, nChars, nActual); + + int logRequests; + getIntegerParam(ADXSPD_LogRequests, &logRequests); + if (status == asynSuccess && logRequests && + (function == NDFilePath || function == NDFileName)) { + try { + this->setRequestLogging(true); + } catch (std::runtime_error& e) { + this->pApi->DisableRequestLogging(); + setIntegerParam(ADXSPD_LogRequests, 0); + ERR_TO_STATUS_ARGS("Failed to update request log file, disabling logging: %s", + e.what()); + status = asynError; + } + callParamCallbacks(); + } + return status; +} + /** * @brief Override of ADDriver base function - reports driver status * diff --git a/xspdApp/src/ADXSPD.h b/xspdApp/src/ADXSPD.h index 25d94b6..2a02e23 100644 --- a/xspdApp/src/ADXSPD.h +++ b/xspdApp/src/ADXSPD.h @@ -174,6 +174,8 @@ class ADXSPD : ADDriver { // ADDriver overrides virtual asynStatus writeInt32(asynUser* pasynUser, epicsInt32 value); virtual asynStatus writeFloat64(asynUser* pasynUser, epicsFloat64 value); + virtual asynStatus writeOctet(asynUser* pasynUser, const char* value, size_t nChars, + size_t* nActual); virtual void report(FILE* fp, int details); // Destructor. Disconnects from the detector and performs cleanup @@ -189,6 +191,7 @@ class ADXSPD : ADDriver { asynStatus refreshFrameSize(); asynStatus acquireStart(); asynStatus acquireStop(); + void setRequestLogging(bool enable); template void subtractFrames(void* currentFrame, void* previousFrame, void* outputFrame, diff --git a/xspdApp/src/ADXSPDParamDefs.cpp b/xspdApp/src/ADXSPDParamDefs.cpp index e825f45..9e050c1 100644 --- a/xspdApp/src/ADXSPDParamDefs.cpp +++ b/xspdApp/src/ADXSPDParamDefs.cpp @@ -35,4 +35,5 @@ void ADXSPD::createAllParams() { createParam(ADXSPD_MonitorIntervalString, asynParamFloat64, &ADXSPD_MonitorInterval); createParam(ADXSPD_DecompressString, asynParamInt32, &ADXSPD_Decompress); createParam(ADXSPD_BloscNumThreadsString, asynParamInt32, &ADXSPD_BloscNumThreads); + createParam(ADXSPD_LogRequestsString, asynParamInt32, &ADXSPD_LogRequests); } diff --git a/xspdApp/src/ADXSPDParamDefs.h b/xspdApp/src/ADXSPDParamDefs.h index c4169fa..82af125 100644 --- a/xspdApp/src/ADXSPDParamDefs.h +++ b/xspdApp/src/ADXSPDParamDefs.h @@ -36,6 +36,7 @@ #define ADXSPD_MonitorIntervalString "XSPD_MONITOR_INTERVAL" #define ADXSPD_DecompressString "XSPD_DECOMPRESS" #define ADXSPD_BloscNumThreadsString "XSPD_BLOSC_NUM_THREADS" +#define ADXSPD_LogRequestsString "XSPD_LOG_REQUESTS" // Parameter index definitions int ADXSPD_ApiVersion; @@ -69,10 +70,11 @@ int ADXSPD_MonitorMode; int ADXSPD_MonitorInterval; int ADXSPD_Decompress; int ADXSPD_BloscNumThreads; +int ADXSPD_LogRequests; #define ADXSPD_FIRST_PARAM ADXSPD_ApiVersion -#define ADXSPD_LAST_PARAM ADXSPD_BloscNumThreads +#define ADXSPD_LAST_PARAM ADXSPD_LogRequests -#define NUM_ADXSPD_PARAMS 31 +#define NUM_ADXSPD_PARAMS 32 #endif diff --git a/xspdApp/src/XSPDAPI.cpp b/xspdApp/src/XSPDAPI.cpp index 5ec6a0a..2c68ffe 100644 --- a/xspdApp/src/XSPDAPI.cpp +++ b/xspdApp/src/XSPDAPI.cpp @@ -1,6 +1,11 @@ #include "XSPDAPI.h" +#include +#include +#include +#include + /** * @brief Parses a version string into its major, minor, and patch components * @@ -290,6 +295,7 @@ string XSPD::API::GetSystemId() { * @return json Parsed JSON response from the API */ json XSPD::API::SubmitRequest(string uri, XSPD::RequestType reqType) { + std::lock_guard lock(this->apiMutex); cpr::Response response; string verbMsg; switch (reqType) { @@ -305,6 +311,8 @@ json XSPD::API::SubmitRequest(string uri, XSPD::RequestType reqType) { throw invalid_argument("Unsupported request type"); } + this->LogRequest(reqType, uri, response.status_code, response.elapsed); + if (response.status_code != 200) throw runtime_error("Failed to " + verbMsg + ": " + response.error.message); @@ -318,6 +326,77 @@ json XSPD::API::SubmitRequest(string uri, XSPD::RequestType reqType) { } } +/** + * @brief Enables logging of each HTTP request submitted to XSPD + * + * @param logFilePath Path of the file to append log entries to. If empty, logs to stdout. + * @throws runtime_error if the log file cannot be opened + */ +void XSPD::API::EnableRequestLogging(const string& logFilePath) { + std::lock_guard lock(this->apiMutex); + if (this->requestLogFile.is_open()) this->requestLogFile.close(); + this->logRequests = false; + + if (!logFilePath.empty()) { + this->requestLogFile.open(logFilePath, ios::out | ios::app); + if (!this->requestLogFile.is_open()) + throw runtime_error("Failed to open request log file " + logFilePath); + } + this->logRequests = true; +} + +/** + * @brief Disables logging of HTTP requests, closing the log file if one is open + */ +void XSPD::API::DisableRequestLogging() { + std::lock_guard lock(this->apiMutex); + this->logRequests = false; + if (this->requestLogFile.is_open()) this->requestLogFile.close(); +} + +/** + * @brief Checks whether HTTP request logging is enabled + * + * @return true if request logging is enabled, false otherwise + */ +bool XSPD::API::IsRequestLoggingEnabled() { + std::lock_guard lock(this->apiMutex); + return this->logRequests; +} + +/** + * @brief Writes a single request log entry, if request logging is enabled + * + * @param reqType The type of HTTP request + * @param uri The full URI the request was sent to + * @param statusCode The HTTP status code of the response (0 if no response was received) + * @param elapsed Time taken to complete the request, in seconds + */ +void XSPD::API::LogRequest(XSPD::RequestType reqType, const string& uri, long statusCode, + double elapsed) { + if (!this->logRequests) return; + + auto now = chrono::system_clock::now(); + time_t nowSec = chrono::system_clock::to_time_t(now); + auto ms = chrono::duration_cast(now.time_since_epoch()) % 1000; + tm localTime; +#ifdef _WIN32 + localtime_s(&localTime, &nowSec); +#else + localtime_r(&nowSec, &localTime); +#endif + + // Format into a local stream so we don't alter the formatting state of stdout + ostringstream entry; + entry << put_time(&localTime, "%Y-%m-%d %H:%M:%S") << "." << setfill('0') << setw(3) + << ms.count() << " | " << magic_enum::enum_name(reqType) << " " << uri + << " | status=" << statusCode << " | elapsed=" << fixed << setprecision(3) + << elapsed * 1000.0 << " ms"; + + ostream& out = this->requestLogFile.is_open() ? this->requestLogFile : cout; + out << entry.str() << endl; +} + /** * @brief Makes a GET request to the XSPD API and returns the parsed JSON response * diff --git a/xspdApp/src/XSPDAPI.h b/xspdApp/src/XSPDAPI.h index 644c431..8b1362a 100644 --- a/xspdApp/src/XSPDAPI.h +++ b/xspdApp/src/XSPDAPI.h @@ -4,10 +4,12 @@ #include #include +#include #include #include #include #include +#include #include #include "nlohmann/json.hpp" @@ -120,6 +122,12 @@ class API { json Get(string endpoint); json Put(string endpoint); + void EnableRequestLogging(const string& logFilePath = ""); + void DisableRequestLogging(); + bool IsRequestLoggingEnabled(); + // Caller must hold apiMutex + void LogRequest(RequestType reqType, const string& uri, long statusCode, double elapsed); + /** * @brief Retrieves the value of a variable from the API * @@ -130,7 +138,6 @@ class API { */ template T GetVar(string varPath, string key = "value") { - std::lock_guard lock(this->apiMutex); // Ensure thread safety for API calls json response = Get("devices/" + this->deviceId + "/variables?path=" + varPath); return ReadVarFromResp(response, varPath, key); } @@ -162,7 +169,6 @@ class API { valueAsStr = to_string(value); } - std::lock_guard lock(this->apiMutex); // Ensure thread safety for API calls json response = this->Put("devices/" + this->deviceId + "/variables?path=" + varPath + "&value=" + valueAsStr); return ReadVarFromResp(response, varPath, rbKey); @@ -230,7 +236,9 @@ class API { } private: - mutex apiMutex; // Mutex to protect API calls and internal state + mutex apiMutex; // Serializes HTTP requests and guards request logging state + bool logRequests = false; + ofstream requestLogFile; // If not open while logging is enabled, requests go to stdout string baseUri, apiVersion, xspdVersion, libxspVersion, deviceId, systemId; vector availableCommands; unique_ptr detector; diff --git a/xspdApp/tests/TestXSPDAPI.cpp b/xspdApp/tests/TestXSPDAPI.cpp index 9f33a55..c112ba6 100644 --- a/xspdApp/tests/TestXSPDAPI.cpp +++ b/xspdApp/tests/TestXSPDAPI.cpp @@ -526,3 +526,44 @@ TEST_F(TestXSPDAPI, TestGetBloscSubcompressorId) { testing::ThrowsMessage( testing::HasSubstr("Compressor ZLIB is not a Blosc compressor"))); } + +TEST_F(TestXSPDAPI, TestRequestLoggingDisabledByDefault) { + ASSERT_FALSE(this->mapi->IsRequestLoggingEnabled()); +} + +TEST_F(TestXSPDAPI, TestRequestLoggingToFile) { + string logFilePath = testing::TempDir() + "xspd_request_log_test.log"; + std::remove(logFilePath.c_str()); + + this->mapi->EnableRequestLogging(logFilePath); + ASSERT_TRUE(this->mapi->IsRequestLoggingEnabled()); + this->mapi->LogRequest(XSPD::RequestType::GET, "localhost:8008/api", 200, 0.0125); + this->mapi->DisableRequestLogging(); + ASSERT_FALSE(this->mapi->IsRequestLoggingEnabled()); + this->mapi->LogRequest(XSPD::RequestType::PUT, "localhost:8008/not_logged", 200, 0.0); + + std::ifstream logFile(logFilePath); + std::stringstream contents; + contents << logFile.rdbuf(); + ASSERT_THAT(contents.str(), testing::HasSubstr("GET localhost:8008/api | status=200 | " + "elapsed=12.500 ms")); + ASSERT_THAT(contents.str(), testing::Not(testing::HasSubstr("not_logged"))); + std::remove(logFilePath.c_str()); +} + +TEST_F(TestXSPDAPI, TestRequestLoggingToStdout) { + this->mapi->EnableRequestLogging(); + std::stringstream captured; + std::streambuf* origBuf = std::cout.rdbuf(captured.rdbuf()); + this->mapi->LogRequest(XSPD::RequestType::PUT, "localhost:8008/api/v1/devices", 404, 0.001); + std::cout.rdbuf(origBuf); + ASSERT_THAT(captured.str(), + testing::HasSubstr("PUT localhost:8008/api/v1/devices | status=404 | elapsed=")); +} + +TEST_F(TestXSPDAPI, TestRequestLoggingInvalidFilePath) { + ASSERT_THAT([&]() { this->mapi->EnableRequestLogging("/nonexistent_dir/xspd.log"); }, + testing::ThrowsMessage( + testing::HasSubstr("Failed to open request log file"))); + ASSERT_FALSE(this->mapi->IsRequestLoggingEnabled()); +}