diff --git a/compile_commands.json b/compile_commands.json new file mode 120000 index 000000000..6de3d79ab --- /dev/null +++ b/compile_commands.json @@ -0,0 +1 @@ +cmake/compile_commands.json \ No newline at end of file diff --git a/patch/civetweb/0001-Increase-niceness-of-all-civetweb-threads-as-DNS-ope.patch b/patch/civetweb/0001-Increase-niceness-of-all-civetweb-threads-as-DNS-ope.patch index fc0fa42a7..554c624ac 100644 --- a/patch/civetweb/0001-Increase-niceness-of-all-civetweb-threads-as-DNS-ope.patch +++ b/patch/civetweb/0001-Increase-niceness-of-all-civetweb-threads-as-DNS-ope.patch @@ -2,14 +2,13 @@ diff --git a/src/webserver/civetweb/civetweb.c b/src/webserver/civetweb/civetweb index da254bb4..b1e5b9a6 100644 --- a/src/webserver/civetweb/civetweb.c +++ b/src/webserver/civetweb/civetweb.c -@@ -244,6 +244,7 @@ static void DEBUG_TRACE_FUNC(const char *func, +@@ -244,5 +244,6 @@ static void DEBUG_TRACE_FUNC(const char *func, #else #include "log.h" +#include #define DEBUG_TRACE(fmt, ...) \ - if(debug_flags[DEBUG_WEBSERVER]) {\ - log_web("DEBUG: " fmt " (%s:%d)", ##__VA_ARGS__, short_path(__FILE__), __LINE__); } + log_web_debug(DEBUG_WEBSERVER, fmt " (%s:%d)", ##__VA_ARGS__, short_path(__FILE__), __LINE__); @@ -2890,6 +2891,9 @@ mg_set_thread_name(const char *name) */ (void)prctl(PR_SET_NAME, threadName, 0, 0, 0); diff --git a/patch/civetweb/0001-Log-debug-messages-to-webserver.log-when-debug.webse.patch b/patch/civetweb/0001-Log-debug-messages-to-webserver.log-when-debug.webse.patch index 5fd5227d3..9b16e3160 100644 --- a/patch/civetweb/0001-Log-debug-messages-to-webserver.log-when-debug.webse.patch +++ b/patch/civetweb/0001-Log-debug-messages-to-webserver.log-when-debug.webse.patch @@ -2,7 +2,7 @@ diff --git a/src/webserver/civetweb/civetweb.c b/src/webserver/civetweb/civetweb index 3df8eab9..9b0c6308 100644 --- a/src/webserver/civetweb/civetweb.c +++ b/src/webserver/civetweb/civetweb.c -@@ -239,9 +239,10 @@ static void DEBUG_TRACE_FUNC(const char *func, +@@ -239,9 +239,9 @@ static void DEBUG_TRACE_FUNC(const char *func, #endif #else @@ -10,8 +10,7 @@ index 3df8eab9..9b0c6308 100644 #define DEBUG_TRACE(fmt, ...) \ - do { \ - } while (0) -+ if(debug_flags[DEBUG_WEBSERVER]) {\ -+ log_web("DEBUG: " fmt " (%s:%d)", ##__VA_ARGS__, short_path(__FILE__), __LINE__); } ++ log_web_debug(DEBUG_WEBSERVER, fmt " (%s:%d)", ##__VA_ARGS__, short_path(__FILE__), __LINE__); #endif /* DEBUG */ #endif /* DEBUG_TRACE */ - + diff --git a/src/CMakeLists.txt b/src/CMakeLists.txt index 95118ab02..c136cb656 100644 --- a/src/CMakeLists.txt +++ b/src/CMakeLists.txt @@ -409,6 +409,44 @@ else() target_compile_definitions(civetweb PRIVATE NO_SSL) endif() +set(USE_SYSTEMD_JOURNAL "AUTO" CACHE STRING "Build FTL with systemd journal support (AUTO, DLOPEN, COMPILE, OFF)") +set_property(CACHE USE_SYSTEMD_JOURNAL PROPERTY STRINGS AUTO DLOPEN COMPILE OFF) + +find_library(LIBSYSTEMD NAMES libsystemd${LIBRARY_SUFFIX} systemd) +check_include_file("systemd/sd-journal.h" HAVE_SD_JOURNAL_H) +find_library(LIBDL dl) +if(USE_SYSTEMD_JOURNAL STREQUAL "OFF") + message(STATUS "Building FTL with systemd journal support: NO") +elseif(USE_SYSTEMD_JOURNAL STREQUAL "COMPILE") + if(NOT LIBSYSTEMD OR NOT HAVE_SD_JOURNAL_H) + message(FATAL_ERROR "COMPILE mode requested but systemd headers/library not found") + endif() + message(STATUS "Building FTL with systemd journal support: COMPILE") + target_compile_definitions(core PRIVATE HAVE_SYSTEMD_JOURNAL) + target_link_libraries(pihole-FTL ${LIBSYSTEMD}) +elseif(USE_SYSTEMD_JOURNAL STREQUAL "DLOPEN") + if(NOT LIBDL) + message(FATAL_ERROR "DLOPEN mode requested but dl library not found") + endif() + target_link_libraries(pihole-FTL ${LIBDL}) + message(STATUS "Building FTL with systemd journal support: DLOPEN") + target_compile_definitions(core PRIVATE DL_SYSTEMD_JOURNAL) +elseif(USE_SYSTEMD_JOURNAL STREQUAL "AUTO") + if(LIBSYSTEMD AND HAVE_SD_JOURNAL_H) + message(STATUS "Building FTL with systemd journal support: AUTO → COMPILE mode") + target_compile_definitions(core PRIVATE HAVE_SYSTEMD_JOURNAL) + target_link_libraries(pihole-FTL ${LIBSYSTEMD}) + elseif(LIBDL) + target_link_libraries(pihole-FTL ${LIBDL}) + message(STATUS "Building FTL with systemd journal support: AUTO → DLOPEN fallback") + target_compile_definitions(core PRIVATE DL_SYSTEMD_JOURNAL) + else() + message(FATAL_ERROR "AUTO mode requested but neither LIBSYSTEMD nor LIBDL are available") + endif() +else() + message(FATAL_ERROR "Invalid USE_SYSTEMD_JOURNAL: ${USE_SYSTEMD_JOURNAL}") +endif() + # After finishing building the FTL binary, we append the sha256sum of the binary # in raw form to itself and print the checksum to the console add_custom_command(TARGET pihole-FTL POST_BUILD COMMENT "Appending sha256sum to pihole-FTL" diff --git a/src/args.c b/src/args.c index d6f517921..5df795096 100644 --- a/src/args.c +++ b/src/args.c @@ -80,6 +80,10 @@ // test #include +#ifdef DL_SYSTEMD_JOURNAL +#include +#endif + // defined in dnsmasq.c extern void print_dnsmasq_version(const char *yellow, const char *green, const char *bold, const char *normal); @@ -91,6 +95,7 @@ extern int sqlite3_rsync_main(int argc, char **argv); bool debug_mode = false; bool daemonmode = true, cli_mode = false; +bool log_json = false, log_journal = false; int argc_dnsmasq = 0; const char** argv_dnsmasq = NULL; @@ -219,6 +224,33 @@ static bool strStartsWithIgnoreCase(const char *input, const char *start) return strncasecmp(input, start, strlen(start)) == 0; } +#ifdef DL_SYSTEMD_JOURNAL +static void *systemd_handle = NULL; +sd_journal_send_t sd_journal_send = NULL; + +// Intentionally never dlclose() libsystemd +// We open it once and use it until late shutdown +// OS cleanup at exit is sufficient. +static bool init_systemd_journal(void) +{ + systemd_handle = dlopen("libsystemd.so.0", RTLD_NOW | RTLD_LOCAL); + if (!systemd_handle) + return false; + + dlerror(); + sd_journal_send = (sd_journal_send_t)dlsym(systemd_handle, "sd_journal_send"); + const char *err = dlerror(); + if (err != NULL) { + dlclose(systemd_handle); + systemd_handle = NULL; + sd_journal_send = NULL; + return false; + } + + return true; +} +#endif + void parse_args(int argc, char *argv[]) { bool quiet = false; @@ -1104,6 +1136,33 @@ void parse_args(int argc, char *argv[]) ok = true; } + if(strcmp(argv[i], "--log-json") == 0) + { + log_json = true; + ok = true; + } + + if(strcmp(argv[i], "--log-journal") == 0 && log_journal == false) + { +#ifdef HAVE_SYSTEMD_JOURNAL + log_journal = true; + ok = true; +#elif defined(DL_SYSTEMD_JOURNAL) + + if(!init_systemd_journal()) + { + printf("Error: Failed to load libsystemd. Logging to journal is not available.\n"); + exit(EXIT_FAILURE); + } + + log_journal = true; + ok = true; +#else + printf("Error: FTL was compiled without systemd support. Logging to journal is not available.\n"); + exit(EXIT_FAILURE); +#endif + } + // Regex test mode if(strcmp(argv[i], "regex-test") == 0) { diff --git a/src/args.h b/src/args.h index 43adf2f3f..f268d6c6f 100644 --- a/src/args.h +++ b/src/args.h @@ -13,6 +13,7 @@ void parse_args(int argc, char *argv[]); extern bool daemonmode, cli_mode; +extern bool log_json, log_journal; extern int argc_dnsmasq; extern const char ** argv_dnsmasq; @@ -56,4 +57,9 @@ void test_dnsmasq_options(int argc, const char *argv[]); #define COL_CYAN "\x1b[96m" // bright foreground color #define CLI_OVER "\r\x1b[K" // go back to beginning of line and erase to end of line +#ifdef DL_SYSTEMD_JOURNAL +typedef int (*sd_journal_send_t)(const char *format, ...); +extern sd_journal_send_t sd_journal_send; +#endif + #endif //ARGS_H diff --git a/src/dnsmasq/dnsmasq.c b/src/dnsmasq/dnsmasq.c index 764664224..830b89c26 100644 --- a/src/dnsmasq/dnsmasq.c +++ b/src/dnsmasq/dnsmasq.c @@ -171,9 +171,14 @@ int main_dnsmasq (int argc, char **argv) ensure that we're not using those fds for real stuff. */ for (i = 0; i < 3; i++) open("/dev/null", O_RDWR); + + /**** Pi-hole modification ****/ + // don't close all fds, as this would close the journald socket /* Close any file descriptors we inherited apart from std{in|out|err} */ - close_fds(max_fd, -1, -1, -1); + //close_fds(max_fd, -1, -1, -1); + + /*****************************/ #ifndef HAVE_LINUX_NETWORK # if !(defined(IP_RECVDSTADDR) && defined(IP_RECVIF) && defined(IP_SENDSRCADDR)) @@ -728,19 +733,24 @@ int main_dnsmasq (int argc, char **argv) log_err = log_start(ent_pw, err_pipe[1]); - if (!option_bool(OPT_DEBUG)) - { - /* open stdout etc to /dev/null */ - int nullfd = open("/dev/null", O_RDWR); - if (nullfd != -1) - { - dup2(nullfd, STDOUT_FILENO); - dup2(nullfd, STDERR_FILENO); - dup2(nullfd, STDIN_FILENO); - close(nullfd); - } - } + /**** Pi-hole modification ****/ + // We want to log to stdout/stderr, so we are preventing dnsmasq from replacing them with /dev/null + //if (!option_bool(OPT_DEBUG)) + // { + // /* open stdout etc to /dev/null */ + // int nullfd = open("/dev/null", O_RDWR); + // if (nullfd != -1) + // { + // dup2(nullfd, STDOUT_FILENO); + // dup2(nullfd, STDERR_FILENO); + // dup2(nullfd, STDIN_FILENO); + // close(nullfd); + // } + // } + + /******************************/ + /* if we are to run scripts, we need to fork a helper before dropping root. */ daemon->helperfd = -1; #ifdef HAVE_SCRIPT diff --git a/src/dnsmasq/log.c b/src/dnsmasq/log.c index 4d17a423b..f60e081e1 100644 --- a/src/dnsmasq/log.c +++ b/src/dnsmasq/log.c @@ -327,7 +327,8 @@ void my_syslog(int priority, const char *format, ...) va_start(ap, format); len = vsnprintf(buffer, MAX_MESSAGE, format, ap) + 1u; /* include zero-terminator */ va_end(ap); - FTL_dnsmasq_log(buffer, len > MAX_MESSAGE ? MAX_MESSAGE : len); + time(&time_now); + FTL_dnsmasq_log(buffer, priority, len > MAX_MESSAGE ? MAX_MESSAGE : len, time_now); /*******************************************************************************/ if (echo_stderr) @@ -408,8 +409,10 @@ void my_syslog(int priority, const char *format, ...) for (tmp = entries; tmp->next; tmp = tmp->next); tmp->next = entry; } - - time(&time_now); + /************** Pi-hole modification **************/ + // get the current time earlier, so JSON logging and logfile use the same timestamp + //time(&time_now); + /**************************************************/ p = entry->payload; if (!log_to_file) p += sprintf(p, "<%d>", priority | log_fac); diff --git a/src/dnsmasq_interface.c b/src/dnsmasq_interface.c index 15fc404cc..b49f22f5f 100644 --- a/src/dnsmasq_interface.c +++ b/src/dnsmasq_interface.c @@ -59,6 +59,12 @@ // init_api_sessions() #include "api/api.h" +#ifdef HAVE_SYSTEMD_JOURNAL +#define SD_JOURNAL_SUPPRESS_LOCATION +// sd_journal_send() +#include +#endif + // Public prototypes (defined in this file, called from other translation units) void FTL_dump_cache_stats(void); @@ -1652,7 +1658,7 @@ static bool special_domain(const queriesData *query, const char *domain) // _dns.resolver.arpa. 86400 IN SVCB 2 dns.google. alpn="h2,h3" key7="/dns-query{?dns}" // // RFC 9462, Section 4 says: - // + // // If the recursive resolver that receives this query has no Designated // Resolvers, it SHOULD return NODATA for queries to the "resolver.arpa" // zone, to provide a consistent and accurate signal to clients that it @@ -1902,7 +1908,7 @@ static bool FTL_check_blocking(const char *domainstr, queriesData *query, client } // when we reach this point: the query is not in FTL's cache (for this client) - + // Check exact whitelist for match const char *blockedDomain = domainstr; PERF_START(_pcb_allow); @@ -4098,16 +4104,46 @@ static void _query_set_dnssec(queriesData *query, const enum dnssec_status dnsse } // Add dnsmasq log line to internal FIFO buffer (can be queried via the API) -void FTL_dnsmasq_log(const char *payload, const int length) +void FTL_dnsmasq_log(const char *payload, const int priority, const int length, const time_t now) { // Lock SHM lock_shm(); + const char *prio = priostr(priority, DEBUG_GENERIC); + // Add to FIFO buffer - add_to_fifo_buffer(FIFO_DNSMASQ, payload, NULL, length); + add_to_fifo_buffer(FIFO_DNSMASQ, payload, prio, length); // Unlock SHM unlock_shm(); + + if(log_json && !daemonmode) + { + // Get and log PID of current process to avoid ambiguities when more than one + // pihole-FTL instance is logging to the same output + char idstr[42]; + get_idstr(idstr, sizeof(idstr)); + + // JSON logging only for stdout + log_to_json( + now, + prio, + "dnsmasq", + idstr, + payload + ); + } +#if defined(HAVE_SYSTEMD_JOURNAL) || defined(DL_SYSTEMD_JOURNAL) + if(log_journal) + { + sd_journal_send( + "MESSAGE=%s", payload, + "PRIORITY=%i", priority, + "COMPONENT=dnsmasq", + NULL + ); + } +#endif } static const char *check_dnsmasq_name(const char *name) diff --git a/src/dnsmasq_interface.h b/src/dnsmasq_interface.h index 250d67cca..725141a4b 100644 --- a/src/dnsmasq_interface.h +++ b/src/dnsmasq_interface.h @@ -16,6 +16,8 @@ #include "edns0.h" #include "metrics.h" +#include + enum protocol { TCP, UDP, INTERNAL }; void FTL_hook(unsigned int flags, const char *name, const union all_addr *addr, char *arg, int id, unsigned short type, const char *file, const int line); @@ -56,6 +58,6 @@ bool get_dnsmasq_debug(void) __attribute__ ((pure)); // defined in src/dnsmasq/cache.c extern char *querystr(char *desc, unsigned short type); -extern void FTL_dnsmasq_log(const char *payload, const int length); +extern void FTL_dnsmasq_log(const char *payload, const int priority, const int length, const time_t now); #endif // DNSMASQ_INTERFACE_H diff --git a/src/enums.h b/src/enums.h index 9398c3985..2110d4995 100644 --- a/src/enums.h +++ b/src/enums.h @@ -159,7 +159,8 @@ enum debug_flag { DEBUG_NETLINK, DEBUG_TIMING, DEBUG_PERFORMANCE, - DEBUG_MAX + DEBUG_MAX, + DEBUG_GENERIC // this is for getting a regular "DEBUG" string from priostr(); it is explicitly not selectable as a debug flag, only for carrying over the generic syslog level. } __attribute__ ((packed)); enum events { diff --git a/src/log.c b/src/log.c index b4b298daf..e2f6dc313 100644 --- a/src/log.c +++ b/src/log.c @@ -28,6 +28,13 @@ #include "database/query-table.h" // runGC() #include "gc.h" +#include "webserver/cJSON/cJSON.h" + +#ifdef HAVE_SYSTEMD_JOURNAL +#define SD_JOURNAL_SUPPRESS_LOCATION +// sd_journal_send() +#include +#endif static bool print_log = true, print_stdout = true; static bool ftl_log_available = true; @@ -52,7 +59,7 @@ void init_FTL_log(const char *name) if(config.files.log.ftl.v.s != NULL) { FILE *logfile = NULL; - if((logfile = fopen(config.files.log.ftl.v.s, "a+")) == NULL) + if((logfile = fopen(config.files.log.ftl.v.s, "a")) == NULL) { printf("ERROR: Opening of FTL log (%s) failed: %s\nUsing syslog instead!\n", config.files.log.ftl.v.s, strerror(errno)); @@ -123,6 +130,92 @@ void get_timestr(char timestring[TIMESTR_SIZE], const time_t timein, const bool timestring[TIMESTR_SIZE - 1] = '\0'; } +void get_timestr_iso8601(char timestring[TIMESTR_SIZE], const time_t timein, const bool millis) +{ + struct tm tm; + localtime_r(&timein, &tm); + + int millisec = 0; + + // Optional milliseconds + if(millis) + { + struct timeval tv; + gettimeofday(&tv, NULL); + + // Only use ms if the timestamps match the same second + if(tv.tv_sec == timein) + millisec = tv.tv_usec / 1000; + } + + // Timezone offset in seconds east of UTC + const long tz_offset = tm.tm_gmtoff; + + // UTC special case + if(tz_offset == 0) + { + if(millis) + { + snprintf(timestring, TIMESTR_SIZE, + "%04d-%02d-%02dT%02d:%02d:%02d.%03dZ", + tm.tm_year + 1900, + tm.tm_mon + 1, + tm.tm_mday, + tm.tm_hour, + tm.tm_min, + tm.tm_sec, + millisec); + } + else + { + snprintf(timestring, TIMESTR_SIZE, + "%04d-%02d-%02dT%02d:%02d:%02dZ", + tm.tm_year + 1900, + tm.tm_mon + 1, + tm.tm_mday, + tm.tm_hour, + tm.tm_min, + tm.tm_sec); + } + } + else + { + const int tz_hours = (int)(tz_offset / 3600); + const int tz_minutes = (int)((labs(tz_offset) % 3600) / 60); + + if(millis) + { + snprintf(timestring, TIMESTR_SIZE, + "%04d-%02d-%02dT%02d:%02d:%02d.%03d%+03d:%02d", + tm.tm_year + 1900, + tm.tm_mon + 1, + tm.tm_mday, + tm.tm_hour, + tm.tm_min, + tm.tm_sec, + millisec, + tz_hours, + tz_minutes); + } + else + { + snprintf(timestring, TIMESTR_SIZE, + "%04d-%02d-%02dT%02d:%02d:%02d%+03d:%02d", + tm.tm_year + 1900, + tm.tm_mon + 1, + tm.tm_mday, + tm.tm_hour, + tm.tm_min, + tm.tm_sec, + tz_hours, + tz_minutes); + } + } + + // Ensure null termination + timestring[TIMESTR_SIZE - 1] = '\0'; +} + // Return the current year unsigned int get_year(const time_t timein) { @@ -131,7 +224,53 @@ unsigned int get_year(const time_t timein) return tm.tm_year + 1900; } -static const char * __attribute__((const)) priostr(const int priority, const enum debug_flag flag) +void log_to_json(const time_t now, const char *log_level, const char *component, const char *pid, const char *msg) +{ + char timestring_iso8601[TIMESTR_SIZE]; + get_timestr_iso8601(timestring_iso8601, now, true); + + cJSON *root = cJSON_CreateObject(); + if (!root) return; + + cJSON_AddStringToObject(root, "timestamp", timestring_iso8601); + cJSON_AddStringToObject(root, "log_level", log_level); + cJSON_AddStringToObject(root, "service", "pihole-FTL"); + cJSON_AddStringToObject(root, "component", component); + cJSON_AddStringToObject(root, "pid", pid); + cJSON_AddStringToObject(root, "message", msg); + + char *out = cJSON_PrintUnformatted(root); + cJSON_Delete(root); + + if (!out) return; + printf("%s\n", out); + free(out); +} + +void get_idstr(char *idstr, size_t size) +{ + const int pid = getpid(); // Get the process ID of the calling process + const int mpid = main_pid(); // Get the process ID of the main FTL process + const int tid = gettid(); // Get the thread ID of the calling process + + // There are four cases we have to differentiate here: + if(pid == tid) + if(is_fork(mpid, pid)) + // Fork of the main process + snprintf(idstr, size, "%i/F%i", pid, mpid); + else + // Main process + snprintf(idstr, size, "%iM", pid); + else + if(is_fork(mpid, pid)) + // Thread of a fork of the main process + snprintf(idstr, size, "%i/F%i/T%i", pid, mpid, tid); + else + // Thread of the main process + snprintf(idstr, size, "%i/T%i", pid, tid); +} + +const char * __attribute__((const)) priostr(const int priority, const enum debug_flag flag) { switch (priority) { @@ -233,6 +372,8 @@ const char *debugstr(const enum debug_flag flag) return "DEBUG_PERFORMANCE"; case DEBUG_MAX: return "DEBUG_MAX"; + case DEBUG_GENERIC: + return "DEBUG"; case DEBUG_NONE: // fall through default: return "DEBUG_ANY"; @@ -242,6 +383,7 @@ const char *debugstr(const enum debug_flag flag) void __attribute__ ((format (printf, 3, 4))) _FTL_log(const int priority, const enum debug_flag flag, const char *format, ...) { char timestring[TIMESTR_SIZE]; + const time_t now = time(NULL); va_list args; // We have been explicitly asked to not print anything to the log @@ -249,32 +391,14 @@ void __attribute__ ((format (printf, 3, 4))) _FTL_log(const int priority, const return; // Get human-readable time - get_timestr(timestring, time(NULL), true, false); + get_timestr(timestring, now, true, false); // Get and log PID of current process to avoid ambiguities when more than one // pihole-FTL instance is logging into the same file char idstr[42]; - const int pid = getpid(); // Get the process ID of the calling process - const int mpid = main_pid(); // Get the process ID of the main FTL process - const int tid = gettid(); // Get the thread ID of the calling process - + get_idstr(idstr, sizeof(idstr)); const char *prio = priostr(priority, flag); - // There are four cases we have to differentiate here: - if(pid == tid) - if(is_fork(mpid, pid)) - // Fork of the main process - snprintf(idstr, sizeof(idstr)-1, "%i/F%i", pid, mpid); - else - // Main process - snprintf(idstr, sizeof(idstr)-1, "%iM", pid); - else - if(is_fork(mpid, pid)) - // Thread of a fork of the main process - snprintf(idstr, sizeof(idstr)-1, "%i/F%i/T%i", pid, mpid, tid); - else - // Thread of the main process - snprintf(idstr, sizeof(idstr)-1, "%i/T%i", pid, tid); // Print to stdout before writing to file if((!daemonmode || cli_mode) && print_stdout) @@ -299,10 +423,48 @@ void __attribute__ ((format (printf, 3, 4))) _FTL_log(const int priority, const add_to_fifo_buffer(FIFO_FTL, buffer, prio, len > MAX_MSG_FIFO ? MAX_MSG_FIFO : len); bool logged = false; + + if(log_json && !daemonmode) + { + char json_buffer[8192]; + + va_start(args, format); + vsnprintf(json_buffer, sizeof(json_buffer), format, args); + va_end(args); + // JSON logging only for stdout + log_to_json( + now, + prio, + "FTL", + idstr, + json_buffer + ); + logged = true; + } +#if defined(HAVE_SYSTEMD_JOURNAL) || defined(DL_SYSTEMD_JOURNAL) + if(log_journal) + { + char journal_buffer[8192]; + + va_start(args, format); + vsnprintf(journal_buffer, sizeof(journal_buffer), format, args); + va_end(args); + + sd_journal_send( + "MESSAGE=%s", journal_buffer, + "PRIORITY=%i", priority, + "DEBUG_FLAG=%s", debugstr(flag), + "COMPONENT=FTL", + NULL + ); + logged = true; + } +#endif + if(ftl_log_available && config.files.log.ftl.v.s != NULL) { // Open log file - FILE *logfile = fopen(config.files.log.ftl.v.s, "a+"); + FILE *logfile = fopen(config.files.log.ftl.v.s, "a"); // Write to log file if(logfile != NULL) @@ -339,33 +501,72 @@ void __attribute__ ((format (printf, 3, 4))) _FTL_log(const int priority, const } } -void __attribute__ ((format (printf, 1, 2))) log_web(const char *format, ...) +void __attribute__ ((format (printf, 3, 4))) log_web(const int priority, const enum debug_flag flag, const char *format, ...) { char timestring[TIMESTR_SIZE]; const time_t now = time(NULL); va_list args; + // Get human-readable time + get_timestr(timestring, now, true, false); + + // Get and log PID of current process to avoid ambiguities when more than one + // pihole-FTL instance is logging into the same file + char idstr[42]; + get_idstr(idstr, sizeof(idstr)); + const char *prio = priostr(priority, flag); + // Add line to FIFO buffer char buffer[MAX_MSG_FIFO + 1u]; va_start(args, format); const size_t len = vsnprintf(buffer, MAX_MSG_FIFO, format, args) + 1u; /* include zero-terminator */ va_end(args); - add_to_fifo_buffer(FIFO_WEBSERVER, buffer, NULL, len > MAX_MSG_FIFO ? MAX_MSG_FIFO : len); + add_to_fifo_buffer(FIFO_WEBSERVER, buffer, prio, len > MAX_MSG_FIFO ? MAX_MSG_FIFO : len); - // Get human-readable time - get_timestr(timestring, now, true, false); - // Get and log PID of current process to avoid ambiguities when more than one - // pihole-FTL instance is logging into the same file - const long pid = (long)getpid(); + if(log_json && !daemonmode) + { + char json_buffer[8192]; + + va_start(args, format); + vsnprintf(json_buffer, sizeof(json_buffer), format, args); + va_end(args); + + // JSON logging only for stdout + log_to_json( + now, + prio, + "webserver", + idstr, + json_buffer + ); + } +#if defined(HAVE_SYSTEMD_JOURNAL) || defined(DL_SYSTEMD_JOURNAL) + if(log_journal) + { + char journal_buffer[8192]; + + va_start(args, format); + vsnprintf(journal_buffer, sizeof(journal_buffer), format, args); + va_end(args); + + sd_journal_send( + "MESSAGE=%s", journal_buffer, + "PRIORITY=%i", priority, + "DEBUG_FLAG=%s", debugstr(flag), + "COMPONENT=webserver", + NULL + ); + } +#endif // Open web log file - FILE *weblog = fopen(config.files.log.webserver.v.s, "a+"); + FILE *weblog = fopen(config.files.log.webserver.v.s, "a"); // Write to web log file if(weblog != NULL) { - fprintf(weblog, "[%s %ld] ", timestring, pid); + fprintf(weblog, "%s [%s] %s: ", timestring, idstr, prio); va_start(args, format); vfprintf(weblog, format, args); va_end(args); diff --git a/src/log.h b/src/log.h index 9ba19659c..5bcbd03ce 100644 --- a/src/log.h +++ b/src/log.h @@ -52,8 +52,11 @@ const char *get_FTL_version(void); void log_FTL_version(bool crashreport); double double_time(void); void get_timestr(char timestring[TIMESTR_SIZE], const time_t timein, const bool millis, const bool uri_compatible); +void get_timestr_iso8601(char timestring[TIMESTR_SIZE], const time_t timein, const bool millis); +void log_to_json(const time_t now, const char *log_level, const char *component, const char *pid, const char *msg); +void get_idstr(char *idstr, size_t size); +const char *priostr(const int priority, const enum debug_flag flag) __attribute__((const)); const char *debugstr(const enum debug_flag flag) __attribute__((const)); -void log_web(const char *format, ...) __attribute__ ((format (printf, 1, 2))); const char *get_ordinal_suffix(unsigned int number) __attribute__ ((const)); void print_FTL_version(void); void dnsmasq_diagnosis_warning(char *message); @@ -74,6 +77,11 @@ void FTL_log_dnsmasq_fatal(const char *format, ...) __attribute__ ((format (prin void log_ctrl(bool vlog, bool vstdout); void FTL_log_helper(const unsigned int n, ...); +#define log_web_debug(flag, format, ...) \ + if(flag > -1 && flag < DEBUG_MAX && debug_flags[flag]) \ + log_web(LOG_DEBUG, flag, format, ## __VA_ARGS__) +void log_web(const int priority, const enum debug_flag flag, const char *format, ...) __attribute__ ((format (printf, 3, 4))); + char *escape_string(const char *input) __attribute__ ((malloc)); char *escape_data(const char *src_buf, size_t src_sz) __attribute__((malloc)); diff --git a/src/webserver/civetweb/civetweb.c b/src/webserver/civetweb/civetweb.c index 357d259ed..3f84462b6 100644 --- a/src/webserver/civetweb/civetweb.c +++ b/src/webserver/civetweb/civetweb.c @@ -246,8 +246,7 @@ static void DEBUG_TRACE_FUNC(const char *func, #include "log.h" #include #define DEBUG_TRACE(fmt, ...) \ - if(debug_flags[DEBUG_WEBSERVER]) {\ - log_web("DEBUG: " fmt " (%s:%d)", ##__VA_ARGS__, short_path(__FILE__), __LINE__); } + log_web_debug(DEBUG_WEBSERVER, fmt " (%s:%d)", ##__VA_ARGS__, short_path(__FILE__), __LINE__); #endif /* DEBUG */ #endif /* DEBUG_TRACE */ @@ -4249,12 +4248,12 @@ send_cors_header(struct mg_connection *conn) conn->dom_ctx->config[ACCESS_CONTROL_EXPOSE_HEADERS]; const char *cors_meth_cfg = conn->dom_ctx->config[ACCESS_CONTROL_ALLOW_METHODS]; - const char *cors_repl_asterisk_with_orig_cfg = + const char *cors_repl_asterisk_with_orig_cfg = conn->dom_ctx->config[REPLACE_ASTERISK_WITH_ORIGIN]; - + if (cors_orig_cfg && *cors_orig_cfg && origin_hdr && *origin_hdr && cors_repl_asterisk_with_orig_cfg && *cors_repl_asterisk_with_orig_cfg) { int cors_repl_asterisk_with_orig = mg_strcasecmp(cors_repl_asterisk_with_orig_cfg, "yes"); - + /* Cross-origin resource sharing (CORS), see * http://www.html5rocks.com/en/tutorials/cors/, * http://www.html5rocks.com/static/images/cors_server_flowchart.png @@ -15158,7 +15157,7 @@ handle_request(struct mg_connection *conn) } return; } - + /* 1.3. decode url (if config says so) */ if (should_decode_url(conn)) { @@ -15244,9 +15243,9 @@ handle_request(struct mg_connection *conn) const char *cors_acrm = get_header(ri->http_headers, ri->num_headers, "Access-Control-Request-Method"); - const char *cors_repl_asterisk_with_orig_cfg = + const char *cors_repl_asterisk_with_orig_cfg = conn->dom_ctx->config[REPLACE_ASTERISK_WITH_ORIGIN]; - + /* Todo: check if cors_origin is in cors_orig_cfg. * Or, let the client check this. */ @@ -15255,7 +15254,7 @@ handle_request(struct mg_connection *conn) && (cors_origin != NULL) && (cors_acrm != NULL) && (cors_repl_asterisk_with_orig_cfg != NULL) && (*cors_repl_asterisk_with_orig_cfg != 0)) { int cors_repl_asterisk_with_orig = mg_strcasecmp(cors_repl_asterisk_with_orig_cfg, "yes"); - + /* This is a valid CORS preflight, and the server is configured * to handle it automatically. */ const char *cors_acrh = diff --git a/src/webserver/lua_web.c b/src/webserver/lua_web.c index eb47f2e85..c5a54d7e4 100644 --- a/src/webserver/lua_web.c +++ b/src/webserver/lua_web.c @@ -122,7 +122,7 @@ int request_handler(struct mg_connection *conn, void *cbdata) if(!authorized) { // User is not authenticated, redirect to login page - log_web("Authentication required, redirecting to %s%slogin", + log_web(LOG_INFO, DEBUG_NONE, "Authentication required, redirecting to %s%slogin", config.webserver.paths.prefix.v.s, config.webserver.paths.webhome.v.s); ftl_http_redirect(conn, 302, "%s%slogin", config.webserver.paths.prefix.v.s, @@ -136,7 +136,7 @@ int request_handler(struct mg_connection *conn, void *cbdata) if(authorized) { // User is already authenticated, redirecting to index page - log_web("User is already authenticated, redirecting to %s%s", + log_web(LOG_INFO, DEBUG_NONE, "User is already authenticated, redirecting to %s%s", config.webserver.paths.prefix.v.s, config.webserver.paths.webhome.v.s); ftl_http_redirect(conn, 302, "%s%s", config.webserver.paths.prefix.v.s, diff --git a/src/webserver/webserver.c b/src/webserver/webserver.c index 7cd60c222..208f5047a 100644 --- a/src/webserver/webserver.c +++ b/src/webserver/webserver.c @@ -252,7 +252,7 @@ static int redirect_lp_handler(struct mg_connection *conn, void *input) static int log_http_message(const struct mg_connection *conn, const char *message) { - log_web("%s", message); + log_web(LOG_INFO, DEBUG_NONE, "%s", message); return 1; } @@ -262,7 +262,7 @@ static int log_http_access(const struct mg_connection *conn, const char *message if(!config.debug.api.v.b) return 1; - log_web("ACCESS: %s", message); + log_web(LOG_INFO, DEBUG_NONE, "ACCESS: %s", message); return 1; } @@ -288,7 +288,7 @@ void FTL_mbed_debug(void *user_param, int level, const char *file, int line, con len--; // Log the message - log_web("mbedTLS(%s:%d, %d): %.*s", file, line, level, (int)len, message); + log_web_debug(DEBUG_TLS, "mbedTLS(%s:%d, %d): %.*s", file, line, level, (int)len, message); } /** @@ -598,7 +598,7 @@ void http_init(void) num_threads[sizeof(num_threads) - 1] = '\0'; /* Initialize the library */ - log_web("Initializing HTTP server on ports \"%s\"", config.webserver.port.v.s); + log_web(LOG_INFO, DEBUG_NONE, "Initializing HTTP server on ports \"%s\"", config.webserver.port.v.s); unsigned int features = MG_FEATURES_FILES | MG_FEATURES_IPV6 | MG_FEATURES_CACHE; @@ -609,7 +609,7 @@ void http_init(void) if(mg_init_library(features) == 0) { - log_web("Initializing HTTP library failed!"); + log_web(LOG_ERR, DEBUG_NONE, "Initializing HTTP library failed!"); return; }