From 275b456c966bce52245f028cabc62507ab1e9b13 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?S=C3=B6ren=20Hoffstedt?= Date: Mon, 5 Nov 2018 14:40:17 +0100 Subject: [PATCH 1/6] Added separate file logging to logging utility. --- conf/settings-default.toml | 5 ++++ src/cgi.cpp | 7 ++++- src/mapping_manager.cpp | 3 ++ src/services/httpservice.cpp | 4 +-- src/uploader/uploader_cgi.cpp | 2 +- src/util/log.cpp | 54 +++++++++++++++++++++++++++++++---- src/util/log.h | 17 +++++++++-- 7 files changed, 81 insertions(+), 11 deletions(-) diff --git a/conf/settings-default.toml b/conf/settings-default.toml index a5a481b9..fd80f0a0 100644 --- a/conf/settings-default.toml +++ b/conf/settings-default.toml @@ -66,3 +66,8 @@ location= "tcp:127.0.0.1:10200" # The connection string for the R-Operator to us [uploader] directory="uploader" # The name of the directory where the uploader stores the files + +[log] +logtofile=false #If logs should be written to file instead of error stream +#logfilelocation="" #Location to store the logs +logfilelevel="DEBUG" #The maximum level to be logged to file \ No newline at end of file diff --git a/src/cgi.cpp b/src/cgi.cpp index 818c1f5f..ad5780ae 100644 --- a/src/cgi.cpp +++ b/src/cgi.cpp @@ -61,7 +61,11 @@ void fcgiThread(int fd) { int main() { Configuration::loadFromDefaultPaths(); - Log::off(); + Log::streamAndMemoryOff(); + + if(Configuration::get("log.logtofile")){ + Log::logToFile(); + } /* * Initialize Cache @@ -129,4 +133,5 @@ int main() { threads[i].join(); } } + Log::fileOff(); } diff --git a/src/mapping_manager.cpp b/src/mapping_manager.cpp index d751c3d1..effeb37f 100644 --- a/src/mapping_manager.cpp +++ b/src/mapping_manager.cpp @@ -791,6 +791,9 @@ int main(int argc, char *argv[]) { NopCacheManager cm; CacheManager::init(&cm); + if(Configuration::get("log.logtofile")){ + Log::logToFile(); + } Log::logToStream(Log::LogLevel::WARN, &std::cerr); const char *command = argv[1]; diff --git a/src/services/httpservice.cpp b/src/services/httpservice.cpp index 61fdc65e..a485220c 100644 --- a/src/services/httpservice.cpp +++ b/src/services/httpservice.cpp @@ -71,7 +71,7 @@ void HTTPService::run(std::streambuf *in, std::streambuf *out, std::streambuf *e } } - Log::off(); + Log::streamAndMemoryOff(); } /** @@ -106,7 +106,7 @@ void HTTPService::run(std::streambuf *in, std::streambuf *out, std::streambuf *e response.send500("invalid request"); } } - Log::off(); + Log::streamAndMemoryOff(); } void HTTPService::catchExceptions(HTTPResponseStream& response, const MappingException &me){ diff --git a/src/uploader/uploader_cgi.cpp b/src/uploader/uploader_cgi.cpp index 17fe6987..65622d06 100644 --- a/src/uploader/uploader_cgi.cpp +++ b/src/uploader/uploader_cgi.cpp @@ -7,7 +7,7 @@ int main() { Configuration::loadFromDefaultPaths(); - Log::off(); + Log::streamAndMemoryOff(); UserDB::initFromConfiguration(); UploadService service(std::cin.rdbuf(), std::cout.rdbuf(), std::cerr.rdbuf()); diff --git a/src/util/log.cpp b/src/util/log.cpp index ee109a38..a6c774f2 100644 --- a/src/util/log.cpp +++ b/src/util/log.cpp @@ -9,6 +9,7 @@ #include "util/concat.h" #include "util/exceptions.h" #include "util/enumconverter.h" +#include "util/configuration.h" #include #include @@ -16,6 +17,7 @@ #include #include #include +#include /* @@ -45,6 +47,8 @@ static Log::LogLevel streamlog_level = Log::LogLevel::OFF; static std::mutex log_mutex; +static std::ofstream filelog_stream; +static Log::LogLevel filelog_level = Log::LogLevel::OFF; static void log(Log::LogLevel level, const std::string &msg) { // avoid assembling the message unless it is really needed @@ -71,7 +75,9 @@ static void log(Log::LogLevel level, const std::string &msg) { if (level <= memorylog_level) memorylog.push_back(message); if (level <= streamlog_level && streamlog) - (*streamlog) << message << std::endl; + (*streamlog) << message << std::endl; + if(level <= filelog_level) + filelog_stream << message << std::endl; } static Log::LogLevel levelFromString(const std::string &level) { @@ -100,6 +106,36 @@ static std::string sprintf(const char *msg, va_list arglist) { /* * Initialize the logging */ +void Log::logToFile() { + std::lock_guard guard(log_mutex); + Log::LogLevel level = levelFromString(Configuration::get("log.logfilelevel")); + filelog_level = level; + + if(filelog_level == LogLevel::OFF) + return; + + if(filelog_stream.is_open()){ + throw MustNotHappenException("File logging was already enabled."); + } + + auto t = std::time(nullptr); + auto tm = *std::localtime(&t); + std::stringstream file_name; + file_name << "log_"; + file_name << std::put_time(&tm, "%d-%m-%Y_%H-%M-%S"); + file_name << ".txt"; + + namespace bf = boost::filesystem; + bf::path path(Configuration::get("log.logfilelocation")); + if(!bf::exists(path)){ + bf::create_directory(path); + } + path /= file_name.str(); + filelog_stream.open(path.string()); + + maxLogLevel = std::max(filelog_level, maxLogLevel); +} + void Log::logToStream(const std::string &level, std::ostream *stream) { logToStream(levelFromString(level), stream); } @@ -107,7 +143,7 @@ void Log::logToStream(LogLevel level, std::ostream *stream) { std::lock_guard guard(log_mutex); streamlog_level = level; streamlog = stream; - maxLogLevel = std::max(memorylog_level, streamlog_level); + maxLogLevel = std::max(streamlog_level, maxLogLevel); } void Log::logToMemory(const std::string &level) { @@ -117,7 +153,7 @@ void Log::logToMemory(const std::string &level) { void Log::logToMemory(LogLevel level) { std::lock_guard guard(log_mutex); memorylog_level = level; - maxLogLevel = std::max(memorylog_level, streamlog_level); + maxLogLevel = std::max(memorylog_level, maxLogLevel); } std::vector Log::getMemoryMessages() { @@ -127,13 +163,21 @@ std::vector Log::getMemoryMessages() { return result; } -void Log::off() { +void Log::streamAndMemoryOff() { std::lock_guard guard(log_mutex); memorylog_level = LogLevel::OFF; memorylog.clear(); streamlog_level = LogLevel::OFF; streamlog = nullptr; - maxLogLevel = LogLevel::OFF; + maxLogLevel = std::max(filelog_level, LogLevel::OFF); +} + + +void Log::fileOff() { + std::lock_guard guard(log_mutex); + filelog_level = LogLevel::OFF; + filelog_stream.close(); + maxLogLevel = std::max(streamlog_level, memorylog_level); } /* diff --git a/src/util/log.h b/src/util/log.h index 2c10a558..4bbac310 100644 --- a/src/util/log.h +++ b/src/util/log.h @@ -11,6 +11,7 @@ #include #include #include +#include #include @@ -23,6 +24,13 @@ class Log { OFF, ERROR, WARN, INFO, DEBUG, TRACE }; + /** + * Logs to a file on disc. Parameters can be set in config (enable/disable, file location, log level). + * It will not be disabled with the streamAndMemoryOff() call [former off()]. + * This allows logging on fcgi level without interfering with memory and stream logging. + */ + static void logToFile(); + /** * Logs to a stream, usually std::cerr * There can only be one stream at a time. Calling this again will remove the previous stream. @@ -42,9 +50,14 @@ class Log { static std::vector getMemoryMessages(); /** - * Turns logging off. + * Turns stream and memory logging off. */ - static void off(); + static void streamAndMemoryOff(); + + /** + * Turns file logging off. + */ + static void fileOff(); static void error(const char *msg, ...); static void error(const std::string &msg); From be35766605c1f06b48c47ef3d00449bf4ee984b3 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?S=C3=B6ren=20Hoffstedt?= Date: Mon, 5 Nov 2018 14:42:36 +0100 Subject: [PATCH 2/6] Debug logging for services: fcgi thread start/end, service run, user id, exceptions. --- src/cgi.cpp | 10 ++++++++-- src/services/artifact.cpp | 2 ++ src/services/featurecollectiondb.cpp | 3 ++- src/services/httpservice.cpp | 7 +++++++ src/services/plot.cpp | 3 ++- src/services/provenance.cpp | 2 ++ src/services/user.cpp | 2 ++ src/services/wcs.cpp | 2 ++ src/services/wfs.cpp | 2 ++ src/services/wms.cpp | 1 + 10 files changed, 30 insertions(+), 4 deletions(-) diff --git a/src/cgi.cpp b/src/cgi.cpp index ad5780ae..0a1c7972 100644 --- a/src/cgi.cpp +++ b/src/cgi.cpp @@ -44,7 +44,12 @@ JPEG32: 120703 (90%) * A thread function that handles fcgi request */ void fcgiThread(int fd) { - FCGX_Init(); + std::stringstream id_stream; + id_stream << std::this_thread::get_id(); + std::string thread_id(id_stream.str()); + Log::debug("Start of fcgiThread. Thread thread_id: " + thread_id); + + FCGX_Init(); FCGX_Request request; @@ -54,9 +59,10 @@ void fcgiThread(int fd) { fcgi_streambuf streambuf_in(request.in); fcgi_streambuf streambuf_out(request.out); fcgi_streambuf streambuf_err(request.err); - + Log::debug("Thread is running new service: " + thread_id); HTTPService::run(&streambuf_in, &streambuf_out, &streambuf_err, request); } + Log::debug("End of fcgiThread. Thread thread_id: " + thread_id); } int main() { diff --git a/src/services/artifact.cpp b/src/services/artifact.cpp index a066e565..cb6667a1 100644 --- a/src/services/artifact.cpp +++ b/src/services/artifact.cpp @@ -6,6 +6,7 @@ #include "util/exceptions.h" #include "util/curl.h" #include "util/timeparser.h" +#include "util/log.h" #include #include @@ -62,6 +63,7 @@ void ArtifactService::run() { auto session = UserDB::loadSession(params.get("sessiontoken")); auto user = session->getUser(); + Log::debug("User: " + user.getUserIDString()); if(request == "create") { std::string type = params.get("type"); diff --git a/src/services/featurecollectiondb.cpp b/src/services/featurecollectiondb.cpp index f391e6f2..2c4485dd 100644 --- a/src/services/featurecollectiondb.cpp +++ b/src/services/featurecollectiondb.cpp @@ -1,10 +1,10 @@ #include "datatypes/plot.h" #include "operators/operator.h" - #include "services/ogcservice.h" #include "featurecollectiondb/featurecollectiondb.h" #include "util/enumconverter.h" +#include "util/log.h" static const std::vector< std::pair > featureTypeMap = { std::make_pair(Query::ResultType::POINTS, "points"), @@ -80,6 +80,7 @@ Json::Value FeatureCollectionDBService::metaDataToJson(const FeatureCollectionDB void FeatureCollectionDBService::run() { auto session = UserDB::loadSession(params.get("sessiontoken")); auto& user = session->getUser(); + Log::debug("User: " + user.getUserIDString()); if(!FeatureCollectionDB::isAvailable()){ throw SourceException("FeatureCollectionDB is not available."); diff --git a/src/services/httpservice.cpp b/src/services/httpservice.cpp index a485220c..dc3cabeb 100644 --- a/src/services/httpservice.cpp +++ b/src/services/httpservice.cpp @@ -57,6 +57,8 @@ void HTTPService::run(std::streambuf *in, std::streambuf *out, std::streambuf *e auto servicename = params.get("service"); auto service = HTTPService::getRegisteredService(servicename, params, response, error); + Log::debug("Running new service: " + servicename); + service->run(); } catch(const MappingException &e){ @@ -64,6 +66,7 @@ void HTTPService::run(std::streambuf *in, std::streambuf *out, std::streambuf *e } catch (const std::exception &e) { error << "Request failed with an exception: " << e.what() << "\n"; + Log::debug(e.what()); if (Configuration::get("global.debug", false)) { response.send500(concat("invalid request: ", e.what())); } else { @@ -93,6 +96,8 @@ void HTTPService::run(std::streambuf *in, std::streambuf *out, std::streambuf *e auto servicename = params.get("service"); auto service = HTTPService::getRegisteredService(servicename, params, response, error); + Log::debug("Running new service: " + servicename); + service->run(); } catch(const MappingException &e){ @@ -100,6 +105,7 @@ void HTTPService::run(std::streambuf *in, std::streambuf *out, std::streambuf *e } catch (const std::exception &e) { error << "Request failed with an exception: " << e.what() << "\n"; + Log::debug(e.what()); if (Configuration::get("global.debug", false)) { response.send500(concat("invalid request: ", e.what())); } else { @@ -126,6 +132,7 @@ void HTTPService::catchExceptions(HTTPResponseStream& response, const MappingExc } response.sendHeader("Status", "500 Internal Server Error"); response.sendJSON(exceptionJson); + Log::debug(exceptionJson.asString()); } else { response.send500("invalid request"); } diff --git a/src/services/plot.cpp b/src/services/plot.cpp index 92d96332..cddb61ea 100644 --- a/src/services/plot.cpp +++ b/src/services/plot.cpp @@ -1,7 +1,7 @@ #include "datatypes/plot.h" #include "operators/operator.h" - +#include "util/log.h" #include "services/ogcservice.h" /* @@ -24,6 +24,7 @@ REGISTER_HTTP_SERVICE(PlotService, "plot"); void PlotService::run() { auto session = UserDB::loadSession(params.get("sessiontoken")); auto user = session->getUser(); + Log::debug("User: " + user.getUserIDString()); std::string queryString = params.get("query", ""); if(queryString == "") diff --git a/src/services/provenance.cpp b/src/services/provenance.cpp index cf8ad015..0999606b 100644 --- a/src/services/provenance.cpp +++ b/src/services/provenance.cpp @@ -1,6 +1,7 @@ #include "services/ogcservice.h" #include "operators/operator.h" +#include "util/log.h" /* * This class serves provenance information of a query. @@ -27,6 +28,7 @@ REGISTER_HTTP_SERVICE(ProvenanceService, "provenance"); void ProvenanceService::run() { auto session = UserDB::loadSession(params.get("sessiontoken")); auto user = session->getUser(); + Log::debug("User: " + user.getUserIDString()); std::string type = params.get("type", ""); if(type != "points" && type != "lines" && type != "polygons" && type != "raster") { diff --git a/src/services/user.cpp b/src/services/user.cpp index 1d4eb18a..82652090 100644 --- a/src/services/user.cpp +++ b/src/services/user.cpp @@ -9,6 +9,7 @@ #include #include #include +#include /** * This class provides user specific methods @@ -47,6 +48,7 @@ void UserService::run() { // anything except login is only allowed with a valid session, so check for it. auto session = UserDB::loadSession(params.get("sessiontoken")); auto user = session->getUser(); + Log::debug("User: " + user.getUserIDString()); if (request == "logout") { session->logout(); diff --git a/src/services/wcs.cpp b/src/services/wcs.cpp index 3f221519..09f86c99 100644 --- a/src/services/wcs.cpp +++ b/src/services/wcs.cpp @@ -3,6 +3,7 @@ #include "operators/operator.h" #include "datatypes/raster.h" #include "util/timeparser.h" +#include "util/log.h" /** * Implementation of the OGC WCS standard http://www.opengeospatial.org/standards/wcs @@ -81,6 +82,7 @@ static int getWcsParameterInteger(const std::string &wcsParameterString){ void WCSService::run() { auto session = UserDB::loadSession(params.get("sessiontoken")); auto user = session->getUser(); + Log::debug("User: " + user.getUserIDString()); /*http://www.myserver.org:port/path? * service=WCS &version=2.0 diff --git a/src/services/wfs.cpp b/src/services/wfs.cpp index 3db54a85..c779e9b7 100644 --- a/src/services/wfs.cpp +++ b/src/services/wfs.cpp @@ -6,6 +6,7 @@ #include "pointvisualization/CircleClusteringQuadTree.h" #include "util/timeparser.h" #include "util/enumconverter.h" +#include "util/log.h" #include #include @@ -90,6 +91,7 @@ void WFSService::getCapabilities() { void WFSService::getFeature() { auto session = UserDB::loadSession(params.get("sessiontoken")); auto user = session->getUser(); + Log::debug("User: " + user.getUserIDString()); if(!params.hasParam("typenames")) throw ArgumentException("WFSService: typeNames parameter not specified"); diff --git a/src/services/wms.cpp b/src/services/wms.cpp index 1a67d879..38b24283 100644 --- a/src/services/wms.cpp +++ b/src/services/wms.cpp @@ -27,6 +27,7 @@ REGISTER_HTTP_SERVICE(WMSService, "WMS"); void WMSService::run() { auto session = UserDB::loadSession(params.get("sessiontoken")); auto user = session->getUser(); + Log::debug("User: " + user.getUserIDString()); bool debug = params.getBool("debug", Configuration::get("global.debug", false)); auto query_crsId = parseCrsId(params, "crs"); From 06e0614587e43e99da0b07329bbe7fea5356aef3 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?S=C3=B6ren=20Hoffstedt?= Date: Thu, 8 Nov 2018 21:01:48 +0100 Subject: [PATCH 3/6] Log request IDs. --- src/cgi.cpp | 9 ++++++--- src/util/log.cpp | 22 +++++++++++++++++++++- src/util/log.h | 16 ++++++++++++++++ 3 files changed, 43 insertions(+), 4 deletions(-) diff --git a/src/cgi.cpp b/src/cgi.cpp index 0a1c7972..00c599b7 100644 --- a/src/cgi.cpp +++ b/src/cgi.cpp @@ -47,7 +47,7 @@ void fcgiThread(int fd) { std::stringstream id_stream; id_stream << std::this_thread::get_id(); std::string thread_id(id_stream.str()); - Log::debug("Start of fcgiThread. Thread thread_id: " + thread_id); + Log::debug("Start of thread: " + thread_id); FCGX_Init(); @@ -59,10 +59,12 @@ void fcgiThread(int fd) { fcgi_streambuf streambuf_in(request.in); fcgi_streambuf streambuf_out(request.out); fcgi_streambuf streambuf_err(request.err); - Log::debug("Thread is running new service: " + thread_id); + Log::setThreadRequestId(request.requestId); + Log::debug(concat("New request ", request.requestId, ", on thread ", thread_id)); HTTPService::run(&streambuf_in, &streambuf_out, &streambuf_err, request); + Log::debug(concat("Finished request ", request.requestId)); } - Log::debug("End of fcgiThread. Thread thread_id: " + thread_id); + Log::debug("End of thread: " + thread_id); } int main() { @@ -71,6 +73,7 @@ int main() { if(Configuration::get("log.logtofile")){ Log::logToFile(); + Log::logRequestId(true); } /* diff --git a/src/util/log.cpp b/src/util/log.cpp index a6c774f2..76532784 100644 --- a/src/util/log.cpp +++ b/src/util/log.cpp @@ -50,6 +50,10 @@ static std::mutex log_mutex; static std::ofstream filelog_stream; static Log::LogLevel filelog_level = Log::LogLevel::OFF; +//init request id variables +thread_local int Log::current_request_id = 0; +bool Log::log_request_id = false; + static void log(Log::LogLevel level, const std::string &msg) { // avoid assembling the message unless it is really needed if (level > maxLogLevel) @@ -67,7 +71,13 @@ static void log(Log::LogLevel level, const std::string &msg) { std::ostringstream ss; ss << "[" << buf << std::setfill('0') << std::setw(3) << (millis % 1000) << "] "; ss << "[" << LogLevelConverter.to_string(level) << "] "; - ss << "[" << std::hex << std::this_thread::get_id() << "] " << msg; + if(Log::log_request_id){ + ss << "[" << std::hex << std::this_thread::get_id() << "] "; + ss << "[request: " << std::dec << Log::current_request_id << "] " << msg; + } else { + ss << "[" << std::hex << std::this_thread::get_id() << "] " << msg; + } + std::string message = ss.str(); // Do the actual logging @@ -247,3 +257,13 @@ void Log::trace(const char* msg, ...) { void Log::trace(const std::string &msg) { log(LogLevel::TRACE, msg); } + +void Log::setThreadRequestId(int id) { + std::lock_guard guard(log_mutex); + current_request_id = id; +} + +void Log::logRequestId(bool value) { + std::lock_guard guard(log_mutex); + log_request_id = value; +} diff --git a/src/util/log.h b/src/util/log.h index 4bbac310..8f0cdc03 100644 --- a/src/util/log.h +++ b/src/util/log.h @@ -69,6 +69,22 @@ class Log { static void debug(const std::string &msg); static void trace(const char *msg, ...); static void trace(const std::string &msg); + + /** + * Sets the thread_local variable current_request_id. If logRequestId is set to true + * the request id of the current thread will be written in front of the log messages. + */ + static void setThreadRequestId(int id); + + static bool log_request_id; + + /** + * Set if the current request id will be written before logs. Call setThreadRequestId + * to set the current id for the calling thread. + */ + static void logRequestId(bool value); + + static thread_local int current_request_id; }; #endif /* LOG_H_ */ From eeaa608de01565338ac971ce29e25586793b12dc Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?S=C3=B6ren=20Hoffstedt?= Date: Fri, 9 Nov 2018 13:40:51 +0100 Subject: [PATCH 4/6] Logging to same file in CGI mode, more accurate file names, logging IP in FCGI. --- conf/settings-default.toml | 7 ++++--- src/cgi.cpp | 14 ++++++++++--- src/util/log.cpp | 43 ++++++++++++++++++++++++++------------ src/util/log.h | 9 ++++---- 4 files changed, 50 insertions(+), 23 deletions(-) diff --git a/conf/settings-default.toml b/conf/settings-default.toml index fd80f0a0..5d66d4a1 100644 --- a/conf/settings-default.toml +++ b/conf/settings-default.toml @@ -68,6 +68,7 @@ location= "tcp:127.0.0.1:10200" # The connection string for the R-Operator to us directory="uploader" # The name of the directory where the uploader stores the files [log] -logtofile=false #If logs should be written to file instead of error stream -#logfilelocation="" #Location to store the logs -logfilelevel="DEBUG" #The maximum level to be logged to file \ No newline at end of file +logtofile=false # If logs should be written to file instead of error stream +#logfilelocation="" # Location to store the logs +logfilelevel="DEBUG" # The maximum level to be logged to file +cgilogfilename="gci_logs.txt" # The name for CGI log file, that is shared between program instances. \ No newline at end of file diff --git a/src/cgi.cpp b/src/cgi.cpp index 00c599b7..0db7a6ab 100644 --- a/src/cgi.cpp +++ b/src/cgi.cpp @@ -60,7 +60,9 @@ void fcgiThread(int fd) { fcgi_streambuf streambuf_out(request.out); fcgi_streambuf streambuf_err(request.err); Log::setThreadRequestId(request.requestId); - Log::debug(concat("New request ", request.requestId, ", on thread ", thread_id)); + char * ip_ptr = FCGX_GetParam("REMOTE_ADDR", request.envp); + std::string ip = ip_ptr != nullptr ? ip_ptr : ""; + Log::debug(concat("New request ", request.requestId, " from ip ", ip, ", on thread ", thread_id)); HTTPService::run(&streambuf_in, &streambuf_out, &streambuf_err, request); Log::debug(concat("Finished request ", request.requestId)); } @@ -71,8 +73,10 @@ int main() { Configuration::loadFromDefaultPaths(); Log::streamAndMemoryOff(); + const bool isCgiMode = getenv("FCGI_WEB_SERVER_ADDRS") == nullptr; + if(Configuration::get("log.logtofile")){ - Log::logToFile(); + Log::logToFile(isCgiMode); Log::logRequestId(true); } @@ -120,9 +124,13 @@ int main() { FeatureCollectionDB::initFromConfiguration(); - if (getenv("FCGI_WEB_SERVER_ADDRS") == nullptr) { + if (isCgiMode) { // CGI mode + long time_id = std::chrono::duration_cast(std::chrono::high_resolution_clock::now().time_since_epoch()).count(); + Log::setThreadRequestId(time_id); //time as request id, to differentiate the requests + Log::debug("New CGI request."); HTTPService::run(std::cin.rdbuf(), std::cout.rdbuf(), std::cerr.rdbuf()); + Log::debug("Finished Request."); } else { // FCGI mode diff --git a/src/util/log.cpp b/src/util/log.cpp index 76532784..9fcf4df3 100644 --- a/src/util/log.cpp +++ b/src/util/log.cpp @@ -51,7 +51,7 @@ static std::ofstream filelog_stream; static Log::LogLevel filelog_level = Log::LogLevel::OFF; //init request id variables -thread_local int Log::current_request_id = 0; +thread_local long Log::current_request_id = 0; bool Log::log_request_id = false; static void log(Log::LogLevel level, const std::string &msg) { @@ -116,7 +116,7 @@ static std::string sprintf(const char *msg, va_list arglist) { /* * Initialize the logging */ -void Log::logToFile() { +void Log::logToFile(bool isCgi) { std::lock_guard guard(log_mutex); Log::LogLevel level = levelFromString(Configuration::get("log.logfilelevel")); filelog_level = level; @@ -128,20 +128,37 @@ void Log::logToFile() { throw MustNotHappenException("File logging was already enabled."); } - auto t = std::time(nullptr); - auto tm = *std::localtime(&t); - std::stringstream file_name; - file_name << "log_"; - file_name << std::put_time(&tm, "%d-%m-%Y_%H-%M-%S"); - file_name << ".txt"; - namespace bf = boost::filesystem; bf::path path(Configuration::get("log.logfilelocation")); if(!bf::exists(path)){ - bf::create_directory(path); + bf::create_directory(path); + } + if(isCgi){ + path /= Configuration::get("log.cgilogfilename"); + filelog_stream.open(path.string(), std::ios::app); + } else { + std::stringstream file_name; + + //get time in nanoseconds and seconds. + auto time_point = std::chrono::high_resolution_clock::now(); + auto ns = std::chrono::duration_cast(time_point.time_since_epoch()); + auto s = std::chrono::duration_cast(ns); + std::time_t t = s.count(); + auto tm = *std::localtime(&t); + long fractional_seconds = ns.count() % 1000000; + + //format date and time automatically and add ms and ns by hand with fixed width of 6 digits. + file_name << "log_"; + file_name << std::put_time(&tm, "%d-%m-%Y_%H:%M:%S"); + file_name << "." << std::setw(6) << std::setfill('0') << fractional_seconds; + file_name << ".txt"; + path /= file_name.str(); + filelog_stream.open(path.string()); + } + + if(filelog_stream.fail()){ + throw MappingException("Could not create stream for file logging.", MappingExceptionType::TRANSIENT); } - path /= file_name.str(); - filelog_stream.open(path.string()); maxLogLevel = std::max(filelog_level, maxLogLevel); } @@ -258,7 +275,7 @@ void Log::trace(const std::string &msg) { log(LogLevel::TRACE, msg); } -void Log::setThreadRequestId(int id) { +void Log::setThreadRequestId(long id) { std::lock_guard guard(log_mutex); current_request_id = id; } diff --git a/src/util/log.h b/src/util/log.h index 8f0cdc03..26caa8fc 100644 --- a/src/util/log.h +++ b/src/util/log.h @@ -25,11 +25,12 @@ class Log { }; /** - * Logs to a file on disc. Parameters can be set in config (enable/disable, file location, log level). + * Logs to a file on disc. Parameters can be set in config (enable/disable, file location, log level, cgi log file name). * It will not be disabled with the streamAndMemoryOff() call [former off()]. * This allows logging on fcgi level without interfering with memory and stream logging. + * @param isCgi If isCgi is true every instance of mapping_cgi will log into the same file, else a new file will be created for this fcgi program instance. */ - static void logToFile(); + static void logToFile(bool isCgi); /** * Logs to a stream, usually std::cerr @@ -74,7 +75,7 @@ class Log { * Sets the thread_local variable current_request_id. If logRequestId is set to true * the request id of the current thread will be written in front of the log messages. */ - static void setThreadRequestId(int id); + static void setThreadRequestId(long id); static bool log_request_id; @@ -84,7 +85,7 @@ class Log { */ static void logRequestId(bool value); - static thread_local int current_request_id; + static thread_local long current_request_id; }; #endif /* LOG_H_ */ From f935078170e05fd15b470d8ed8fe0fe674ec9243 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?S=C3=B6ren=20Hoffstedt?= Date: Mon, 12 Nov 2018 11:33:54 +0100 Subject: [PATCH 5/6] Logging: fix compile error in mapping_manager. --- src/mapping_manager.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/mapping_manager.cpp b/src/mapping_manager.cpp index effeb37f..2ffc9da7 100644 --- a/src/mapping_manager.cpp +++ b/src/mapping_manager.cpp @@ -792,7 +792,7 @@ int main(int argc, char *argv[]) { CacheManager::init(&cm); if(Configuration::get("log.logtofile")){ - Log::logToFile(); + Log::logToFile(false); } Log::logToStream(Log::LogLevel::WARN, &std::cerr); From c7f54ab1d7268f53293c044a59815001f827a0a1 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?S=C3=B6ren=20Hoffstedt?= Date: Mon, 12 Nov 2018 14:20:57 +0100 Subject: [PATCH 6/6] Logging the query string in HttpService. --- src/services/httpservice.cpp | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/src/services/httpservice.cpp b/src/services/httpservice.cpp index dc3cabeb..016a360d 100644 --- a/src/services/httpservice.cpp +++ b/src/services/httpservice.cpp @@ -46,6 +46,11 @@ void HTTPService::run(std::streambuf *in, std::streambuf *out, std::streambuf *e std::ostream error(err); HTTPResponseStream response(out); + //read query input to string and log it. reset input istream position to the beginning afterwards. + std::string query_string((std::istreambuf_iterator(in)), std::istreambuf_iterator()); + input.seekg(0, std::ios_base::beg); + Log::debug(query_string); + Log::logToStream(Log::LogLevel::WARN, &error); Log::logToMemory(Log::LogLevel::INFO); try { @@ -85,6 +90,11 @@ void HTTPService::run(std::streambuf *in, std::streambuf *out, std::streambuf *e std::ostream error(err); HTTPResponseStream response(out); + //read query input to string and log it. reset input istream position to the beginning afterwards. + std::string query_string((std::istreambuf_iterator(in)), std::istreambuf_iterator()); + input.seekg(0, std::ios_base::beg); + Log::debug(query_string); + Log::logToStream(Log::LogLevel::WARN, &error); Log::logToMemory(Log::LogLevel::INFO); try {