From 7be0a0d7f44505af2d2aa5e2ce85fb7e8c478a9e Mon Sep 17 00:00:00 2001 From: Daniel Xu Date: Mon, 13 Jul 2015 16:07:30 -0700 Subject: [PATCH 1/6] TS-306 Enable log rotation for diags.log & traffic.out MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This feature provides the ability to rotate any log that is created by the Diags (including diags.log and manager.log) class, as well as traffic.out (the output log). These logs can be rotated either by time or by size, and both of these options can be specified in records.config [see documentation]. While the feature is relatively small, it required a rather large number of internal changes. Therefore, the _rest_ of this commit message will be a high level architectural overview of the changes necessitated by this feature. The class, BaseLogFile, is added and it is intended to be an abstraction for files on disk as well as the stdout/stderr stream. BaseLogFile is used by both LogFile and Diags to help control individual log files. For Diags, each BaseLogFile is created by DiagsConfig. DiagsConfig also sets a few more values unavailable to Diags. LogFile uses BaseLogFile to manage actual files on disk. In some rare cases, LogFile also uses BaseLogFile to manage a stdout or stderr stream. Most of the functionality in BaseLogFile was stripped from LogFile and moved into BaseLogFile. Originally, traffic.out was just a file whose file descriptor was dup2()’d from traffic_cop all the way to traffic_server (by way of fork()/exec()). With this patch, traffic_cop spawns the traffic_manager process with the location of traffic.out specified as flags (—-bind_stdout and -—bind_stderr). traffic_manager creates two BaseLogFile objects, one for each stdout and stderr, both mapped to traffic.out. traffic_manager then spawns the traffic_server process with the same flags, and traffic_server creates two BaseLogFiles in a similar fashion. As for the actual rotation, traffic_manager checks to see if traffic.out needs to be rotated once per iteration of traffic_manager’s main loop. As soon as traffic_manager rotates traffic.out, SIGUSR2 is sent from traffic_manager to traffic_server, and traffic_server catches SIGUSR2 and synchronizes its own BaseLogFiles with the newly created traffic.out file on disk. For rotation of diags.log, a continuation is scheduled every second in traffic_server to see if diags.log needs rotation, and then proceeds to rotate if necessary. manager.log is checked for rotation right after traffic.out is checked for rotation in the main loop of traffic_manager. --- cmd/traffic_cop/traffic_cop.cc | 49 +- cmd/traffic_crashlog/Makefile.am | 1 + cmd/traffic_crashlog/traffic_crashlog.cc | 4 +- cmd/traffic_ctl/Makefile.am | 1 + cmd/traffic_ctl/traffic_ctl.cc | 3 +- cmd/traffic_ctl/traffic_ctl.h | 5 +- cmd/traffic_manager/Makefile.am | 3 +- cmd/traffic_manager/traffic_manager.cc | 69 +++ iocore/aio/test_AIO.cc | 21 +- iocore/eventsystem/test_Buffer.cc | 16 +- iocore/eventsystem/test_Event.cc | 16 +- iocore/net/test_certlookup.cc | 3 +- lib/ts/BaseLogFile.cc | 578 +++++++++++++++++++++++ lib/ts/BaseLogFile.h | 246 ++++++++++ lib/ts/Diags.cc | 404 +++++++++++++++- lib/ts/Diags.h | 46 +- lib/ts/Makefile.am | 2 + lib/ts/ink_file.cc | 37 ++ lib/ts/ink_file.h | 8 + lib/ts/signals.cc | 1 + lib/ts/test_X509HostnameValidator.cc | 3 +- mgmt/RecordsConfig.cc | 14 + proxy/Main.cc | 94 ++++ proxy/Main.h | 2 + proxy/Makefile.am | 1 + proxy/logging/Log.cc | 6 +- proxy/logging/LogConfig.cc | 38 +- proxy/logging/LogFile.cc | 423 ++++------------- proxy/logging/LogFile.h | 112 +---- proxy/logging/LogObject.cc | 2 +- proxy/logging/Makefile.am | 3 +- proxy/shared/DiagsConfig.cc | 36 +- proxy/shared/DiagsConfig.h | 5 +- proxy/shared/Makefile.am | 5 +- 34 files changed, 1650 insertions(+), 607 deletions(-) create mode 100644 lib/ts/BaseLogFile.cc create mode 100644 lib/ts/BaseLogFile.h diff --git a/cmd/traffic_cop/traffic_cop.cc b/cmd/traffic_cop/traffic_cop.cc index 7102f58a32f..f1eab7eaeea 100644 --- a/cmd/traffic_cop/traffic_cop.cc +++ b/cmd/traffic_cop/traffic_cop.cc @@ -94,7 +94,8 @@ static gid_t admin_gid; static bool admin_user_p = false; static char manager_binary[PATH_NAME_MAX] = "traffic_manager"; static char server_binary[PATH_NAME_MAX] = "traffic_server"; -static char manager_options[OPTIONS_LEN_MAX] = ""; +static char manager_options[OPTIONS_LEN_MAX] = ""; + static char log_file[PATH_NAME_MAX] = "traffic.out"; @@ -731,7 +732,6 @@ spawn_manager() char *options[OPTIONS_MAX]; char *last; char *tok; - int log_fd; int err; int key; @@ -767,6 +767,26 @@ spawn_manager() exit(1); } + // Move any traffic.out that we can not write to, out + // of the way (TSqa2232) + // coverity[fs_check_call] + if (access(log_file, W_OK) < 0 && errno == EACCES) { + char old_log_file[PATH_NAME_MAX]; + snprintf(old_log_file, sizeof(old_log_file), "%s.old", log_file); + // coverity[toctou] + rename(log_file, old_log_file); + cop_log(COP_WARNING, "rename %s to %s as it is not accessible.\n", log_file, old_log_file); + } + + // Bind stdout and stderr of traffic_manager to traffic.out + int max_opts_len = OPTIONS_LEN_MAX - strlen(manager_options); + char tm_opt_buf[max_opts_len]; + int cx = snprintf(tm_opt_buf, max_opts_len, " --bind_stdout %s --bind_stderr %s", log_file, log_file); + if (cx >= 0 && cx < max_opts_len) + strcat(manager_options, tm_opt_buf); + else + cop_log(COP_WARNING, "bind_stdout and bind_stderr flags are too long, not binding anything\n"); + cop_log_trace("spawn_manager: Launching %s with options '%s'\n", prog, manager_options); int i; for (i = 0; i < OPTIONS_MAX; i++) { @@ -782,29 +802,8 @@ spawn_manager() } } - // Move any traffic.out that we can not write to, out - // of the way (TSqa2232) - // coverity[fs_check_call] - if (access(log_file, W_OK) < 0 && errno == EACCES) { - char old_log_file[PATH_NAME_MAX]; - snprintf(old_log_file, sizeof(old_log_file), "%s.old", log_file); - // coverity[toctou] - rename(log_file, old_log_file); - cop_log(COP_WARNING, "rename %s to %s as it is not accessible.\n", log_file, old_log_file); - } - // coverity[toctou] - if ((log_fd = open(log_file, O_WRONLY | O_APPEND | O_CREAT, 0644)) < 0) { - cop_log(COP_WARNING, "unable to open log file \"%s\" [%d '%s']\n", log_file, errno, strerror(errno)); - } - err = fork(); if (err == 0) { - if (log_fd >= 0) { - dup2(log_fd, STDOUT_FILENO); - dup2(log_fd, STDERR_FILENO); - close(log_fd); - } - EnableDeathSignal(SIGTERM); err = execv(prog, options); @@ -815,10 +814,6 @@ spawn_manager() exit(1); } - if (log_fd >= 0) { - close(log_fd); - } - manager_failures = 0; cop_log_trace("Leaving spawn_manager()\n"); } diff --git a/cmd/traffic_crashlog/Makefile.am b/cmd/traffic_crashlog/Makefile.am index b977f51e5cf..b0458fecaf0 100644 --- a/cmd/traffic_crashlog/Makefile.am +++ b/cmd/traffic_crashlog/Makefile.am @@ -20,6 +20,7 @@ bin_PROGRAMS = traffic_crashlog AM_CPPFLAGS = \ $(iocore_include_dirs) \ -I$(top_srcdir)/lib \ + -I$(top_srcdir)/lib/ts \ -I$(top_srcdir)/lib/records \ -I$(top_srcdir)/mgmt \ -I$(top_srcdir)/mgmt/utils \ diff --git a/cmd/traffic_crashlog/traffic_crashlog.cc b/cmd/traffic_crashlog/traffic_crashlog.cc index c176a4753bd..d910e0e1df8 100644 --- a/cmd/traffic_crashlog/traffic_crashlog.cc +++ b/cmd/traffic_crashlog/traffic_crashlog.cc @@ -29,6 +29,7 @@ #include "ts/ink_syslog.h" #include "I_RecProcess.h" #include "RecordsConfig.h" +#include "BaseLogFile.h" static int syslog_mode = false; static int debug_mode = false; @@ -91,7 +92,8 @@ main(int /* argc ATS_UNUSED */, const char **argv) crashlog_target target; pid_t parent = getppid(); - diags = new Diags("" /* tags */, "" /* actions */, stderr); + BaseLogFile *base_log_file = new BaseLogFile("stderr"); + diags = new Diags("" /* tags */, "" /* actions */, base_log_file); appVersionInfo.setup(PACKAGE_NAME, "traffic_crashlog", PACKAGE_VERSION, __DATE__, __TIME__, BUILD_MACHINE, BUILD_PERSON, ""); diff --git a/cmd/traffic_ctl/Makefile.am b/cmd/traffic_ctl/Makefile.am index 5b7731bc764..e4ff0769c77 100644 --- a/cmd/traffic_ctl/Makefile.am +++ b/cmd/traffic_ctl/Makefile.am @@ -20,6 +20,7 @@ AM_CPPFLAGS = \ $(iocore_include_dirs) \ -I$(top_srcdir)/lib \ + -I$(top_srcdir)/lib/ts \ -I$(top_srcdir)/lib/records \ -I$(top_srcdir)/mgmt/api/include diff --git a/cmd/traffic_ctl/traffic_ctl.cc b/cmd/traffic_ctl/traffic_ctl.cc index aff4a425eae..de15467c4d5 100644 --- a/cmd/traffic_ctl/traffic_ctl.cc +++ b/cmd/traffic_ctl/traffic_ctl.cc @@ -219,7 +219,8 @@ main(int argc, const char **argv) {subcommand_storage, "storage", "Manipulate cache storage"}, }; - diags = new Diags("" /* tags */, "" /* actions */, stderr); + BaseLogFile *base_log_file = new BaseLogFile("stderr"); + diags = new Diags("" /* tags */, "" /* actions */, base_log_file); // Process command line arguments and dump into variables if (!CtrlProcessArguments(argc, argv, argument_descriptions, countof(argument_descriptions))) { diff --git a/cmd/traffic_ctl/traffic_ctl.h b/cmd/traffic_ctl/traffic_ctl.h index aa1a51ec623..49e9987bb47 100644 --- a/cmd/traffic_ctl/traffic_ctl.h +++ b/cmd/traffic_ctl/traffic_ctl.h @@ -28,8 +28,9 @@ #include "ts/Diags.h" #include "ts/ink_memory.h" #include "mgmtapi.h" -#include "ts/ink_args.h" -#include "ts/I_Version.h" +#include "ink_args.h" +#include "I_Version.h" +#include "BaseLogFile.h" #include #include diff --git a/cmd/traffic_manager/Makefile.am b/cmd/traffic_manager/Makefile.am index fecdd493e74..a099f47daf9 100644 --- a/cmd/traffic_manager/Makefile.am +++ b/cmd/traffic_manager/Makefile.am @@ -28,7 +28,8 @@ AM_CPPFLAGS = \ -I$(top_srcdir)/mgmt/api/include \ -I$(top_srcdir)/mgmt/cluster \ -I$(top_srcdir)/mgmt/utils \ - -I$(top_srcdir)/lib + -I$(top_srcdir)/lib \ + -I$(top_srcdir)/lib/ts AM_LDFLAGS = \ @EXTRA_CXX_LDFLAGS@ \ diff --git a/cmd/traffic_manager/traffic_manager.cc b/cmd/traffic_manager/traffic_manager.cc index cb6d00a99a9..fd734578b11 100644 --- a/cmd/traffic_manager/traffic_manager.cc +++ b/cmd/traffic_manager/traffic_manager.cc @@ -59,6 +59,7 @@ #define FD_THROTTLE_HEADROOM (128 + 64) // TODO: consolidate with THROTTLE_FD_HEADROOM #define DIAGS_LOG_FILENAME "manager.log" + // These globals are still referenced directly by management API. LocalManager *lmgmt = NULL; FileManager *configFiles; @@ -77,6 +78,8 @@ static inkcoreapi DiagsConfig *diagsConfig; static char debug_tags[1024] = ""; static char action_tags[1024] = ""; static bool proxy_off = false; +static char bind_stdout[512] = ""; +static char bind_stderr[512] = ""; static const char *mgmt_path = NULL; @@ -98,6 +101,44 @@ static void SignalAlrmHandler(int sig); static volatile int sigHupNotifier = 0; static void SigChldHandler(int sig); +static void +rotateLogs() +{ + // First, let us synchronously update the rolling config values for both diagslog + // and outputlog. Note that the config values for outputlog in traffic_server + // are never updated past the original instantiation of Diags. This shouldn't + // be an issue since we're never rolling outputlog from traffic_server anyways. + // The reason being is that it is difficult to send a notification from TS to + // TM, informing TM that outputlog has been rolled. It is much easier sending + // a notification (in the form of SIGUSR2) from TM -> TS. + int output_log_roll_int = (int)REC_ConfigReadInteger("proxy.config.output.logfile.rolling_interval_sec"); + int output_log_roll_size = (int)REC_ConfigReadInteger("proxy.config.output.logfile.rolling_size_mb"); + int output_log_roll_enable = (int)REC_ConfigReadInteger("proxy.config.output.logfile.rolling_enabled"); + int diags_log_roll_int = (int)REC_ConfigReadInteger("proxy.config.diags.logfile.rolling_interval_sec"); + int diags_log_roll_size = (int)REC_ConfigReadInteger("proxy.config.diags.logfile.rolling_size_mb"); + int diags_log_roll_enable = (int)REC_ConfigReadInteger("proxy.config.diags.logfile.rolling_enabled"); + diags->config_roll_diagslog((RollingEnabledValues)diags_log_roll_enable, diags_log_roll_int, diags_log_roll_size); + diags->config_roll_outputlog((RollingEnabledValues)output_log_roll_enable, output_log_roll_int, output_log_roll_size); + + // Now we can actually roll the logs (if necessary) + if (diags->should_roll_diagslog()) { + mgmt_log("Rotated %s", DIAGS_LOG_FILENAME); + } + + if (diags->should_roll_outputlog()) { + // send a signal to TS to reload traffic.out, so the logfile is kept + // synced across processes + mgmt_log("Sending SIGUSR2 to TS"); + pid_t tspid = lmgmt->watched_process_pid; + if (tspid <= 0) + return; + if (kill(tspid, SIGUSR2) != 0) + mgmt_log("Could not send SIGUSR2 to TS: %s", strerror(errno)); + else + mgmt_log("Succesfully sent SIGUSR2 to TS!"); + } +} + static bool is_server_idle() { @@ -413,6 +454,8 @@ main(int argc, const char **argv) {"tsArgs", '-', "Additional arguments for traffic_server", "S*", &tsArgs, NULL, NULL}, {"proxyPort", '-', "HTTP port descriptor", "S*", &proxy_port, NULL, NULL}, {"proxyBackDoor", '-', "Management port", "I", &proxy_backdoor, NULL, NULL}, + {"bind_stdout", '-', "Regular file to bind stdout to", "S512", &bind_stdout, "PROXY_BIND_STDOUT", NULL}, + {"bind_stderr", '-', "Regular file to bind stderr to", "S512", &bind_stderr, "PROXY_BIND_STDERR", NULL}, #if TS_USE_DIAGS {"debug", 'T', "Vertical-bar-separated Debug Tags", "S1023", debug_tags, NULL, NULL}, {"action", 'B', "Vertical-bar-separated Behavior Tags", "S1023", action_tags, NULL, NULL}, @@ -451,6 +494,8 @@ main(int argc, const char **argv) // up the manager diagsConfig = new DiagsConfig(DIAGS_LOG_FILENAME, debug_tags, action_tags, false); diags = diagsConfig->diags; + diags->set_stdout_output(bind_stdout); + diags->set_stderr_output(bind_stderr); diags->prefix_str = "Manager "; RecLocalInit(); @@ -497,6 +542,8 @@ main(int argc, const char **argv) diags = diagsConfig->diags; RecSetDiags(diags); diags->prefix_str = "Manager "; + diags->set_stdout_output(bind_stdout); + diags->set_stderr_output(bind_stderr); if (is_debug_tag_set("diags")) diags->dump(); @@ -565,6 +612,25 @@ main(int argc, const char **argv) lmgmt->proxy_options = tsArgs; mgmt_log(stderr, "[main] Traffic Server Args: '%s'\n", lmgmt->proxy_options); } + + // we must pass in bind_stdout and bind_stderr values to TS + // we do it so TS is able to create BaseLogFiles for each value + if (strcmp(bind_stdout, "") != 0) { + lmgmt->proxy_options = + (char *)ats_realloc(lmgmt->proxy_options, strlen(lmgmt->proxy_options) + 1 /* space */ + + strlen("--bind_stdout ") + strlen(bind_stdout) + 1 /* null term */); + strcat(lmgmt->proxy_options, " --bind_stdout "); + strcat(lmgmt->proxy_options, bind_stdout); + } + + if (strcmp(bind_stderr, "") != 0) { + lmgmt->proxy_options = + (char *)ats_realloc(lmgmt->proxy_options, strlen(lmgmt->proxy_options) + 1 /* space */ + + strlen("--bind_stderr ") + strlen(bind_stderr) + 1 /* null term */); + strcat(lmgmt->proxy_options, " --bind_stderr "); + strcat(lmgmt->proxy_options, bind_stderr); + } + if (proxy_port) { HttpProxyPort::loadValue(lmgmt->m_proxy_ports, proxy_port); } @@ -664,6 +730,9 @@ main(int argc, const char **argv) lmgmt->processEventQueue(); lmgmt->pollMgmtProcessServer(); + // Handle rotation of output log (aka traffic.out) + rotateLogs(); + // Check for a SIGHUP if (sigHupNotifier != 0) { mgmt_log(stderr, "[main] Reading Configuration Files due to SIGHUP\n"); diff --git a/iocore/aio/test_AIO.cc b/iocore/aio/test_AIO.cc index ae6cbe6bbd9..63f1bfb6ac2 100644 --- a/iocore/aio/test_AIO.cc +++ b/iocore/aio/test_AIO.cc @@ -101,29 +101,12 @@ reconfigure_diags() static void init_diags(const char *bdt, const char *bat) { - FILE *diags_log_fp; char diags_logpath[500]; strcpy(diags_logpath, DIAGS_LOG_FILE); - diags_log_fp = fopen(diags_logpath, "w"); - if (diags_log_fp) { - int status; - status = setvbuf(diags_log_fp, NULL, _IOLBF, 512); - if (status != 0) { - fclose(diags_log_fp); - diags_log_fp = NULL; - } - } - - diags = new Diags(bdt, bat, diags_log_fp); - - if (diags_log_fp == NULL) { - Warning("couldn't open diags log file '%s', " - "will not log to this file", - diags_logpath); - } + BaseLogFile *blf = new BaseLogFile(diags_logpath); + diags = new Diags(bdt, bat, blf); - Status("opened %s", diags_logpath); reconfigure_diags(); } diff --git a/iocore/eventsystem/test_Buffer.cc b/iocore/eventsystem/test_Buffer.cc index 825c77ef971..06ccf619c60 100644 --- a/iocore/eventsystem/test_Buffer.cc +++ b/iocore/eventsystem/test_Buffer.cc @@ -91,23 +91,13 @@ reconfigure_diags() static void init_diags(const char *bdt, const char *bat) { - FILE *diags_log_fp; char diags_logpath[500]; ink_strlcpy(diags_logpath, DIAGS_LOG_FILE, sizeof(diags_logpath)); - diags_log_fp = fopen(diags_logpath, "w"); - if (diags_log_fp) { - int status; - status = setvbuf(diags_log_fp, NULL, _IOLBF, 512); - if (status != 0) { - fclose(diags_log_fp); - diags_log_fp = NULL; - } - } - - diags = new Diags(bdt, bat, diags_log_fp); + BaseLogFile *blf = new BaseLogFile(diags_logpath); + diags = new Diags(bdt, bat, blf); - if (diags_log_fp == NULL) { + if (blf && blf->m_fp == NULL) { Warning("couldn't open diags log file '%s', " "will not log to this file", diags_logpath); diff --git a/iocore/eventsystem/test_Event.cc b/iocore/eventsystem/test_Event.cc index 9af7e88a98a..b480db7c8c5 100644 --- a/iocore/eventsystem/test_Event.cc +++ b/iocore/eventsystem/test_Event.cc @@ -91,23 +91,13 @@ reconfigure_diags() static void init_diags(const char *bdt, const char *bat) { - FILE *diags_log_fp; char diags_logpath[500]; strcpy(diags_logpath, DIAGS_LOG_FILE); - diags_log_fp = fopen(diags_logpath, "w"); - if (diags_log_fp) { - int status; - status = setvbuf(diags_log_fp, NULL, _IOLBF, 512); - if (status != 0) { - fclose(diags_log_fp); - diags_log_fp = NULL; - } - } - - diags = new Diags(bdt, bat, diags_log_fp); + BaseLogFile *blf = new BaseLogFile(diags_logpath); + diags = new Diags(bdt, bat, blf); - if (diags_log_fp == NULL) { + if (blf && blf->m_fp == NULL) { Warning("couldn't open diags log file '%s', " "will not log to this file", diags_logpath); diff --git a/iocore/net/test_certlookup.cc b/iocore/net/test_certlookup.cc index 717f2871e57..3989a81e786 100644 --- a/iocore/net/test_certlookup.cc +++ b/iocore/net/test_certlookup.cc @@ -206,7 +206,8 @@ SSLReleaseContext(SSL_CTX *ctx) int main(int argc, const char **argv) { - diags = new Diags(NULL, NULL, stdout); + BaseLogFile *blf = new BaseLogFile("stdout"); + diags = new Diags(NULL, NULL, blf); res_track_memory = 1; SSL_library_init(); diff --git a/lib/ts/BaseLogFile.cc b/lib/ts/BaseLogFile.cc new file mode 100644 index 00000000000..a15152d7184 --- /dev/null +++ b/lib/ts/BaseLogFile.cc @@ -0,0 +1,578 @@ +/** @file + + Base class for log files implementation + + @section license License + + Licensed to the Apache Software Foundation (ASF) under one + or more contributor license agreements. See the NOTICE file + distributed with this work for additional information + regarding copyright ownership. The ASF licenses this file + to you under the Apache License, Version 2.0 (the + "License"); you may not use this file except in compliance + with the License. You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + + Unless required by applicable law or agreed to in writing, software + distributed under the License is distributed on an "AS IS" BASIS, + WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + See the License for the specific language governing permissions and + limitations under the License. + */ + +#include "BaseLogFile.h" + +/* + * This consturctor creates a BaseLogFile based on a given name. + * This is the most common way BaseLogFiles are created. + */ +BaseLogFile::BaseLogFile(const char *name) + : m_name(ats_strdup(name)), m_hostname(NULL), m_is_regfile(false), m_has_signature(false), m_signature(0), m_is_init(false) +{ + m_fp = NULL; + m_start_time = time(0); + m_end_time = 0L; + m_bytes_written = 0; + m_meta_info = NULL; + + log_log_trace("exiting BaseLogFile constructor, m_name=%s, this=%p\n", m_name, this); +} + +/* + * This consturctor creates a BaseLogFile based on a given name. + * Similar to above constructor, but is overloaded with the object signature + */ +BaseLogFile::BaseLogFile(const char *name, uint64_t sig) + : m_name(ats_strdup(name)), m_hostname(NULL), m_is_regfile(false), m_has_signature(true), m_signature(sig), m_is_init(false) +{ + m_fp = NULL; + m_start_time = time(0); + m_end_time = 0L; + m_bytes_written = 0; + m_meta_info = NULL; + + log_log_trace("exiting BaseLogFile constructor, m_name=%s, this=%p\n", m_name, this); +} + +/* + * This copy constructor creates a BaseLogFile based on a given copy. + */ +BaseLogFile::BaseLogFile(const BaseLogFile ©) + : m_fp(NULL), m_start_time(copy.m_start_time), m_end_time(0L), m_bytes_written(0), m_name(ats_strdup(copy.m_name)), + m_hostname(ats_strdup(m_hostname)), m_is_regfile(false), m_has_signature(copy.m_has_signature), m_signature(copy.m_signature), + m_is_init(copy.m_is_init), m_meta_info(NULL) +{ + log_log_trace("exiting BaseLogFile copy constructor, m_name=%s, this=%p\n", m_name, this); +} + +/* + * Destructor. + */ +BaseLogFile::~BaseLogFile() +{ + log_log_trace("entering BaseLogFile destructor, m_name=%s, this=%p\n", m_name, this); + + if (m_is_regfile) + close_file(); + else + log_log_trace("not a regular file, not closing, m_name=%s, this=%p\n", m_name, this); + if (m_name) + ats_free(m_name); + if (m_hostname) + ats_free(m_hostname); + + log_log_trace("exiting BaseLogFile destructor, this=%p\n", this); +} + +/* + * This function is called by a client of BaseLogFile to roll the underlying + * file The tricky part to this routine is in coming up with the new file name, + * which contains the bounding timestamp interval for the entries + * within the file. + + * Under normal operating conditions, this BaseLogFile object was in existence + * for all writes to the file. In this case, the LogFile members m_start_time + * and m_end_time will have the starting and ending times for the actual + * entries written to the file. + + * On restart situations, it is possible to re-open an existing BaseLogFile, + * which means that the m_start_time variable will be later than the actual + * entries recorded in the file. In this case, we'll use the creation time + * of the file, which should be recorded in the meta-information located on + * disk. + + * If we can't use the meta-file, either because it's not there or because + * it's not valid, then we'll use timestamp 0 (Jan 1, 1970) as the starting + * bound. + + * Return 1 if file rolled, 0 otherwise + */ +int +BaseLogFile::roll(long interval_start, long interval_end) +{ + // First, let's see if a roll is even needed. + if (m_name == NULL || !BaseLogFile::exists(m_name)) { + log_log_trace("Roll not needed for %s; file doesn't exist\n", (m_name) ? m_name : "no_name\n"); + return 0; + } + + // Then, check if this object is backing a regular file + if (!m_is_regfile) { + log_log_trace("Roll not needed for %s; not regular file\n", (m_name) ? m_name : "no_name\n"); + return 0; + } + + // Read meta info if needed (if file was not opened) + if (!m_meta_info) { + m_meta_info = new BaseMetaInfo(m_name); + } + + // Create the new file name, which consists of a timestamp and rolled + // extension added to the previous file name. The timestamp format is + // ".%Y%m%d.%Hh%Mm%Ss-%Y%m%d.%Hh%Mm%Ss", where the two date/time values + // represent the starting and ending times for entries in the rolled + // log file. In addition, we add the hostname. So, the entire rolled + // format is something like: + // + // "squid.log.mymachine.19980712.12h00m00s-19980713.12h00m00s.old" + char roll_name[LOGFILE_ROLL_MAXPATHLEN]; + char start_time_ext[64]; + char end_time_ext[64]; + time_t start, end; + + // Make sure the file is closed so we don't leak any descriptors. + close_file(); + + // Start with conservative values for the start and end bounds, then + // try to refine. + start = 0L; + end = (interval_end >= m_end_time) ? interval_end : m_end_time; + + if (m_meta_info->data_from_metafile()) { + // If the metadata came from the metafile, this means that + // the file was preexisting, so we can't use m_start_time for + // our starting bounds. Instead, we'll try to use the file + // creation time stored in the metafile (if it's valid and we can + // read it). If all else fails, we'll use 0 for the start time. + log_log_trace("in BaseLogFile::roll(..) used metadata starttime"); + m_meta_info->get_creation_time(&start); + } else { + // The logfile was not preexisting (normal case), so we'll use + // earlier of the interval start time and the m_start_time. + // + // note that m_start_time is not the time of the first + // transaction, but the time of the creation of the first log + // buffer used by the file. These times may be different, + // especially under light load, and using the m_start_time may + // produce overlapping filenames (the problem is that we have + // no easy way of keeping track of the timestamp of the first + // transaction + log_log_trace("in BaseLogFile::roll(..) used else math starttime\n"); + if (interval_start == 0) + start = m_start_time; + else + start = (m_start_time < interval_start) ? m_start_time : interval_start; + } + log_log_trace("in BaseLogFile::roll(..), start = %ld, m_start_time = %ld, interval_start = %ld\n", start, m_start_time, + interval_start); + + // Now that we have our timestamp values, convert them to the proper + // timestamp formats and create the rolled file name. + timestamp_to_str((long)start, start_time_ext, 64); + timestamp_to_str((long)end, end_time_ext, 64); + snprintf(roll_name, LOGFILE_ROLL_MAXPATHLEN, "%s%s%s.%s-%s%s", m_name, (m_hostname ? LOGFILE_SEPARATOR_STRING : ""), + (m_hostname ? m_hostname : ""), start_time_ext, end_time_ext, LOGFILE_ROLLED_EXTENSION); + + // It may be possible that the file we want to roll into already + // exists. If so, then we need to add a version tag to the rolled + // filename as well so that we don't clobber existing files. + int version = 1; + while (BaseLogFile::exists(roll_name)) { + log_log_trace("The rolled file %s already exists; adding version " + "tag %d to avoid clobbering the existing file.\n", + roll_name, version); + snprintf(roll_name, LOGFILE_ROLL_MAXPATHLEN, "%s%s%s.%s-%s.%d%s", m_name, (m_hostname ? LOGFILE_SEPARATOR_STRING : ""), + (m_hostname ? m_hostname : ""), start_time_ext, end_time_ext, version, LOGFILE_ROLLED_EXTENSION); + version++; + } + + // It's now safe to rename the file. + if (::rename(m_name, roll_name) < 0) { + log_log_error("Traffic Server could not rename logfile %s to %s, error %d: " + "%s.\n", + m_name, roll_name, errno, strerror(errno)); + return 0; + } + + // reset m_start_time + m_start_time = 0; + m_bytes_written = 0; + + log_log_trace("The logfile %s was rolled to %s.\n", m_name, roll_name); + + return 1; +} + +/* + * The more convienent rolling function. Intended use is for less + * critical logs such as diags.log or traffic.out, since _exact_ + * timestamps may be less important + * + * The function calls roll(long,long) with these parameters: + * Start time is either 0 or creation time stored in the metafile, + * whichever is greater + * + * End time is the current time + * + * Returns 1 on success, 0 otherwise + */ +int +BaseLogFile::roll() +{ + long start; + time_t now = time(NULL); + + if (!m_meta_info || !m_meta_info->get_creation_time(&start)) + start = 0L; + + return roll(start, now); +} + + +/* + * This function will return true if the given filename corresponds to a + * rolled logfile. We make this determination based on the file extension. + */ +bool +BaseLogFile::rolled_logfile(char *path) +{ + const int target_len = (int)strlen(LOGFILE_ROLLED_EXTENSION); + int len = (int)strlen(path); + if (len > target_len) { + char *str = &path[len - target_len]; + if (!strcmp(str, LOGFILE_ROLLED_EXTENSION)) { + return true; + } + } + return false; +} + +/* + * Returns if the provided file in 'pathname' exists or not + */ +bool +BaseLogFile::exists(const char *pathname) +{ + ink_assert(pathname != NULL); + return (pathname && ::access(pathname, F_OK) == 0); +} + +/* + * Opens the BaseLogFile and associated BaseMetaInfo on disk if it exists + * Returns relevant exit status + */ +int +BaseLogFile::open_file(int perm) +{ + log_log_trace("BaseLogFile: entered open_file()\n"); + if (is_open()) { + return LOG_FILE_NO_ERROR; + } + + if (m_name && !strcmp(m_name, "stdout")) { + log_log_trace("BaseLogFile: stdout opened\n"); + m_fp = stdout; + m_is_init = true; + return LOG_FILE_NO_ERROR; + } else if (m_name && !strcmp(m_name, "stderr")) { + log_log_trace("BaseLogFile: stderr opened\n"); + m_fp = stderr; + m_is_init = true; + return LOG_FILE_NO_ERROR; + } + + // get root; destructor will release access + // ElevateAccess accesss(true); + + // means this object is representing a real file on disk + m_is_regfile = true; + + // Check to see if the file exists BEFORE we try to open it, since + // opening it will also create it. + bool file_exists = BaseLogFile::exists(m_name); + + if (file_exists) { + if (!m_meta_info) { + // This object must be fresh since it has not built its MetaInfo + // so we create a new MetaInfo object that will read right away + // (in the constructor) the corresponding metafile + m_meta_info = new BaseMetaInfo(m_name); + } + } else { + // The log file does not exist, so we create a new MetaInfo object + // which will save itself to disk right away (in the constructor) + if (m_has_signature) + m_meta_info = new BaseMetaInfo(m_name, (long)time(0), m_signature); + else + m_meta_info = new BaseMetaInfo(m_name, (long)time(0)); + } + + // open actual log file (not metainfo) + log_log_trace("BaseLogFile: attempting to open %s\n", m_name); + m_fp = fopen(m_name, "a+"); + + // error check + if (!m_fp) { + log_log_error("Error opening log file %s: %s\n", m_name, strerror(errno)); + log_log_error("Actual error: %s\n", (errno == EINVAL ? "einval" : "something else")); + return LOG_FILE_COULD_NOT_OPEN_FILE; + } + + // set permissions if necessary + if (perm != -1) { + // means LogFile passed in some permissions we need to set + if (chmod(m_name, perm) != 0) + log_log_error("Error changing logfile=%s permissions: %s\n", m_name, strerror(errno)); + } + + // set m_bytes_written to force the rolling based on filesize. + m_bytes_written = fseek(m_fp, 0, SEEK_CUR); + + log_log_trace("BaseLogFile %s is now open (fd=%d)\n", m_name, fileno(m_fp)); + m_is_init = true; + return LOG_FILE_NO_ERROR; +} + +/* + * Closes actual log file, not metainfo + */ +void +BaseLogFile::close_file() +{ + if (is_open()) { + fclose(m_fp); + log_log_trace("BaseLogFile %s is closed\n", m_name); + m_fp = NULL; + m_is_init = false; + } +} + +/* + * Changes names of the actual log file (not metainfo) + */ +void +BaseLogFile::change_name(const char *new_name) +{ + ats_free(m_name); + m_name = ats_strdup(new_name); +} + +void +BaseLogFile::display(FILE *fd) +{ + fprintf(fd, "Logfile: %s, %s\n", get_name(), (is_open()) ? "file is open" : "file is not open"); +} + +/* + * Lowest level internal logging facility for BaseLogFile + * + * Since BaseLogFiles can potentially be created before the bootstrap + * instance of Diags is ready, we cannot simply call something like Debug(). + * However, we still need to log the creation of BaseLogFile, since the + * information is still useful. This function will print out log messages + * into traffic.out if we happen to be bootstrapping Diags. Since + * traffic_cop redirects stdout/stderr into traffic.out, that + * redirection is inherited by way of exec()/fork() all the way here. + * + * TODO use Debug() for non bootstrap instances + */ +void +BaseLogFile::log_log(LogLogPriorityLevel priority, const char *format, ...) +{ + va_list args; + + const char *priority_name = NULL; + FILE *output = stdout; + switch (priority) { + case LL_Debug: + priority_name = "DEBUG"; + break; + case LL_Note: + priority_name = "NOTE"; + break; + case LL_Warning: + priority_name = "WARNING"; + output = stderr; + break; + case LL_Error: + priority_name = "ERROR"; + output = stderr; + break; + case LL_Fatal: + priority_name = "FATAL"; + output = stderr; + break; + default: + priority_name = "unknown priority"; + } + + va_start(args, format); + struct timeval now; + double now_f; + + gettimeofday(&now, NULL); + now_f = now.tv_sec + now.tv_usec / 1000000.0f; + + fprintf(output, "<%.4f> [%s]: ", now_f, priority_name); + vfprintf(output, format, args); + fflush(output); + + va_end(args); +} + + +/**************************************************************************** + + BaseMetaInfo methods + +*****************************************************************************/ + +/* + * Given a file name (with or without the full path, but without the extension name), + * this function creates appends the ".meta" extension and stores it in the local + * variable + */ +void +BaseMetaInfo::_build_name(const char *filename) +{ + int i = -1, l = 0; + char c; + while (c = filename[l], c != 0) { + if (c == '/') { + i = l; + } + ++l; + } + + // 7 = 1 (dot at beginning) + 5 (".meta") + 1 (null terminating) + // + _filename = (char *)ats_malloc(l + 7); + + if (i < 0) { + ink_string_concatenate_strings(_filename, ".", filename, ".meta", NULL); + } else { + memcpy(_filename, filename, i + 1); + ink_string_concatenate_strings(&_filename[i + 1], ".", &filename[i + 1], ".meta", NULL); + } +} + +/* + * Reads in meta info into the local variables + */ +void +BaseMetaInfo::_read_from_file() +{ + _flags |= DATA_FROM_METAFILE; // mark attempt + int fd = open(_filename, O_RDONLY); + if (fd < 0) { + log_log_error("Could not open metafile %s for reading: %s\n", _filename, strerror(errno)); + } else { + _flags |= FILE_OPEN_SUCCESSFUL; + SimpleTokenizer tok('=', SimpleTokenizer::OVERWRITE_INPUT_STRING); + int line_number = 1; + while (ink_file_fd_readline(fd, BUF_SIZE, _buffer) > 0) { + tok.setString(_buffer); + char *t = tok.getNext(); + if (t) { + if (strcmp(t, "creation_time") == 0) { + t = tok.getNext(); + if (t) { + _creation_time = (time_t)ink_atoi64(t); + _flags |= VALID_CREATION_TIME; + } + } else if (strcmp(t, "object_signature") == 0) { + t = tok.getNext(); + if (t) { + _log_object_signature = ink_atoi64(t); + _flags |= VALID_SIGNATURE; + log_log_trace("BaseMetaInfo::_read_from_file\n" + "\tfilename = %s\n" + "\tsignature string = %s\n" + "\tsignature value = %" PRIu64 "\n", + _filename, t, _log_object_signature); + } + } else if (line_number == 1) { + ink_release_assert(!"no panda support"); + } + } + ++line_number; + } + close(fd); + } +} + +/* + * Writes out metadata info onto disk + */ +void +BaseMetaInfo::_write_to_file() +{ + // get root + // ElevateAccess follows RAII design, the destructor will release root + ElevateAccess accesss(true); + + int fd = open(_filename, O_WRONLY | O_CREAT | O_TRUNC, LOGFILE_DEFAULT_PERMS); + if (fd < 0) { + log_log_error("Could not open metafile %s for writing: %s\n", _filename, strerror(errno)); + return; + } + log_log_trace("Successfully opened metafile=%s\n", _filename); + + int n; + if (_flags & VALID_CREATION_TIME) { + log_log_trace("Writing creation time to %s\n", _filename); + n = snprintf(_buffer, BUF_SIZE, "creation_time = %lu\n", (unsigned long)_creation_time); + // TODO modify this runtime check so that it is not an assertion + ink_release_assert(n <= BUF_SIZE); + if (write(fd, _buffer, n) == -1) { + log_log_trace("Could not write creation_time"); + } + } + + if (_flags & VALID_SIGNATURE) { + log_log_trace("Writing signature to %s\n", _filename); + n = snprintf(_buffer, BUF_SIZE, "object_signature = %" PRIu64 "\n", _log_object_signature); + // TODO modify this runtime check so that it is not an assertion + ink_release_assert(n <= BUF_SIZE); + if (write(fd, _buffer, n) == -1) { + log_log_error("Could not write object_signaure\n"); + } + log_log_trace("BaseMetaInfo::_write_to_file\n" + "\tfilename = %s\n" + "\tsignature value = %" PRIu64 "\n" + "\tsignature string = %s\n", + _filename, _log_object_signature, _buffer); + } + + close(fd); +} + +/* + * This routine will convert a timestamp (seconds) into a short string, + * of the format "%Y%m%d.%Hh%Mm%Ss". + * + * Since the resulting buffer is passed in, this routine is thread-safe. + * Return value is the number of characters placed into the array, not + * including the NULL. + */ + +int +BaseLogFile::timestamp_to_str(long timestamp, char *buf, int size) +{ + static const char *format_str = "%Y%m%d.%Hh%Mm%Ss"; + struct tm res; + struct tm *tms; + tms = ink_localtime_r((const time_t *)×tamp, &res); + return strftime(buf, size, format_str, tms); +} diff --git a/lib/ts/BaseLogFile.h b/lib/ts/BaseLogFile.h new file mode 100644 index 00000000000..e2938fe994a --- /dev/null +++ b/lib/ts/BaseLogFile.h @@ -0,0 +1,246 @@ +/** @file + + Base class for log files + + @section license License + + Licensed to the Apache Software Foundation (ASF) under one + or more contributor license agreements. See the NOTICE file + distributed with this work for additional information + regarding copyright ownership. The ASF licenses this file + to you under the Apache License, Version 2.0 (the + "License"); you may not use this file except in compliance + with the License. You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + + Unless required by applicable law or agreed to in writing, software + distributed under the License is distributed on an "AS IS" BASIS, + WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + See the License for the specific language governing permissions and + limitations under the License. + + */ + + +#ifndef BASE_LOG_FILE_H +#define BASE_LOG_FILE_H + +#include +#include +#include +#include +#include +#include +#include + +#include "ink_memory.h" +#include "ink_string.h" +#include "ink_file.h" +#include "ink_cap.h" +#include "ink_time.h" +#include "SimpleTokenizer.h" + +#define LOGFILE_ROLLED_EXTENSION ".old" +#define LOGFILE_SEPARATOR_STRING "_" +#define LOGFILE_DEFAULT_PERMS (0644) +#define LOGFILE_ROLL_MAXPATHLEN 4096 +#define BASELOGFILE_DEBUG_MODE 0 // change this to 1 to enable debug messages + +typedef enum { + LL_Debug = 0, // process does not die + LL_Note, // process does not die + LL_Warning, // process does not die + LL_Error, // process does not die + LL_Fatal, // causes process termination +} LogLogPriorityLevel; + +#define log_log_trace(...) \ + do { \ + if (BASELOGFILE_DEBUG_MODE) \ + BaseLogFile::log_log(LL_Debug, __VA_ARGS__); \ + } while (0) + +#define log_log_error(...) \ + do { \ + if (BASELOGFILE_DEBUG_MODE) \ + BaseLogFile::log_log(LL_Error, __VA_ARGS__); \ + } while (0) + +/* + * + * BaseMetaInfo class + * + * Used to store persistent information between ATS instances + * + */ +class BaseMetaInfo +{ +public: + enum { + DATA_FROM_METAFILE = 1, // metadata was read (or attempted to) + // from metafile + VALID_CREATION_TIME = 2, // creation time is valid + VALID_SIGNATURE = 4, // signature is valid + // (i.e., creation time only) + FILE_OPEN_SUCCESSFUL = 8 // metafile was opened successfully + }; + + enum { + BUF_SIZE = 640 // size of read/write buffer + }; + +private: + char *_filename; // the name of the meta file + time_t _creation_time; // file creation time + uint64_t _log_object_signature; // log object signature + int _flags; // metainfo status flags + char _buffer[BUF_SIZE]; // read/write buffer + + void _read_from_file(); + void _write_to_file(); + void _build_name(const char *filename); + +public: + BaseMetaInfo(const char *filename) : _flags(0) + { + _build_name(filename); + _read_from_file(); + } + + BaseMetaInfo(char *filename, time_t creation) : _creation_time(creation), _flags(VALID_CREATION_TIME) + { + _build_name(filename); + _write_to_file(); + } + + BaseMetaInfo(char *filename, time_t creation, uint64_t signature) + : _creation_time(creation), _log_object_signature(signature), _flags(VALID_CREATION_TIME | VALID_SIGNATURE) + { + _build_name(filename); + _write_to_file(); + } + + ~BaseMetaInfo() { ats_free(_filename); } + + bool + get_creation_time(time_t *time) + { + if (_flags & VALID_CREATION_TIME) { + *time = _creation_time; + return true; + } else { + return false; + } + } + + bool + get_log_object_signature(uint64_t *signature) + { + if (_flags & VALID_SIGNATURE) { + *signature = _log_object_signature; + return true; + } else { + return false; + } + } + + bool + data_from_metafile() const + { + return (_flags & DATA_FROM_METAFILE ? true : false); + } + + bool + file_open_successful() + { + return (_flags & FILE_OPEN_SUCCESSFUL ? true : false); + } +}; + + +/* + * + * BaseLogFile Class + * + */ +class BaseLogFile +{ +public: + // member functions + BaseLogFile(const char *name); + BaseLogFile(const char *name, uint64_t sig); + BaseLogFile(const BaseLogFile &); + ~BaseLogFile(); + int roll(); + int roll(long interval_start, long interval_end); + static bool rolled_logfile(char *path); + static bool exists(const char *pathname); + int open_file(int perm = -1); + void close_file(); + void change_name(const char *new_name); + void display(FILE *fd = stdout); + const char * + get_name() const + { + return m_name; + } + bool + is_open() + { + return (m_fp != NULL); + } + off_t + get_size_bytes() const + { + return m_bytes_written; + } + bool + is_init() + { + return m_is_init; + } + const char * + get_hostname() const + { + return m_hostname; + } + void + set_hostname(const char *hn) + { + if (m_hostname) + ats_free(m_hostname); + m_hostname = ats_strdup(hn); + } + + static void log_log(LogLogPriorityLevel priority, const char *format, ...); + + // member variables + enum { + LOG_FILE_NO_ERROR = 0, + LOG_FILE_COULD_NOT_OPEN_FILE, + }; + + FILE *m_fp; + long m_start_time; + long m_end_time; + volatile uint64_t m_bytes_written; + +private: + // member functions not allowed + BaseLogFile(); + BaseLogFile &operator=(const BaseLogFile &); + + // member functions + int timestamp_to_str(long timestamp, char *buf, int size); + + // member variables + char *m_name; + char *m_hostname; + bool m_is_regfile; + bool m_has_signature; + uint64_t m_signature; + bool m_is_init; + BaseMetaInfo *m_meta_info; +}; +#endif diff --git a/lib/ts/Diags.cc b/lib/ts/Diags.cc index da8b9a994eb..61fc1c7d590 100644 --- a/lib/ts/Diags.cc +++ b/lib/ts/Diags.cc @@ -101,13 +101,14 @@ SrcLoc::str(char *buf, int buflen) const // ////////////////////////////////////////////////////////////////////////////// -Diags::Diags(const char *bdt, const char *bat, FILE *_diags_log_fp) - : diags_log_fp(_diags_log_fp), magic(DIAGS_MAGIC), show_location(0), base_debug_tags(NULL), base_action_tags(NULL) +Diags::Diags(const char *bdt, const char *bat, BaseLogFile *_diags_log) + : stdout_log(NULL), stderr_log(NULL), magic(DIAGS_MAGIC), show_location(0), base_debug_tags(NULL), base_action_tags(NULL) { int i; cleanup_func = NULL; ink_mutex_init(&tag_table_lock, "Diags::tag_table_lock"); + ink_mutex_init(&rotate_lock, "Diags::rotate_lock"); //////////////////////////////////////////////////////// // initialize the default, base debugging/action tags // @@ -131,6 +132,15 @@ Diags::Diags(const char *bdt, const char *bat, FILE *_diags_log_fp) config.outputs[i].to_diagslog = true; } + // create default stdout and stderr BaseLogFile objects + // (in case the user of this class doesn't specify in the future) + stdout_log = new BaseLogFile("stdout"); + stderr_log = new BaseLogFile("stderr"); + stdout_log->open_file(); // should never fail + stderr_log->open_file(); // should never fail + + setup_diagslog(_diags_log); + ////////////////////////////////////////////////////////////////// // start off with empty tag tables, will build in reconfigure() // ////////////////////////////////////////////////////////////////// @@ -138,11 +148,34 @@ Diags::Diags(const char *bdt, const char *bat, FILE *_diags_log_fp) activated_tags[DiagsTagType_Debug] = NULL; activated_tags[DiagsTagType_Action] = NULL; prefix_str = ""; + + outputlog_rolling_enabled = RollingEnabledValues::NO_ROLLING; + outputlog_rolling_interval = -1; + outputlog_rolling_size = -1; + diagslog_rolling_enabled = RollingEnabledValues::NO_ROLLING; + diagslog_rolling_interval = -1; + diagslog_rolling_size = -1; + + outputlog_time_last_roll = time(0); + diagslog_time_last_roll = time(0); } Diags::~Diags() { - diags_log_fp = NULL; + if (diags_log) { + delete diags_log; + diags_log = NULL; + } + + if (stdout_log) { + delete stdout_log; + stdout_log = NULL; + } + + if (stderr_log) { + delete stderr_log; + stderr_log = NULL; + } ats_free((void *)base_debug_tags); ats_free((void *)base_action_tags); @@ -282,42 +315,46 @@ Diags::print_va(const char *debug_tag, DiagsLevel diags_level, const SrcLoc *loc lock(); if (config.outputs[diags_level].to_diagslog) { - if (diags_log_fp) { + if (diags_log && diags_log->m_fp) { va_list ap_scratch; va_copy(ap_scratch, ap); buffer = format_buf_w_ts; - vfprintf(diags_log_fp, buffer, ap_scratch); + vfprintf(diags_log->m_fp, buffer, ap_scratch); { int len = strlen(buffer); if (len > 0 && buffer[len - 1] != '\n') { - putc('\n', diags_log_fp); + putc('\n', diags_log->m_fp); } } } } if (config.outputs[diags_level].to_stdout) { - va_list ap_scratch; - va_copy(ap_scratch, ap); - buffer = format_buf_w_ts; - vfprintf(stdout, buffer, ap_scratch); - { - int len = strlen(buffer); - if (len > 0 && buffer[len - 1] != '\n') { - putc('\n', stdout); + if (stdout_log && stdout_log->m_fp) { + va_list ap_scratch; + va_copy(ap_scratch, ap); + buffer = format_buf_w_ts; + vfprintf(stdout_log->m_fp, buffer, ap_scratch); + { + int len = strlen(buffer); + if (len > 0 && buffer[len - 1] != '\n') { + putc('\n', stdout_log->m_fp); + } } } } if (config.outputs[diags_level].to_stderr) { - va_list ap_scratch; - va_copy(ap_scratch, ap); - buffer = format_buf_w_ts; - vfprintf(stderr, buffer, ap_scratch); - { - int len = strlen(buffer); - if (len > 0 && buffer[len - 1] != '\n') { - putc('\n', stderr); + if (stderr_log && stderr_log->m_fp) { + va_list ap_scratch; + va_copy(ap_scratch, ap); + buffer = format_buf_w_ts; + vfprintf(stderr_log->m_fp, buffer, ap_scratch); + { + int len = strlen(buffer); + if (len > 0 && buffer[len - 1] != '\n') { + putc('\n', stderr_log->m_fp); + } } } } @@ -547,3 +584,326 @@ Diags::error_va(DiagsLevel level, const char *file, const char *func, const int ink_fatal_va(format_string, ap2); } } + +/* + * Sets up and error handles the given BaseLogFile object to work + * with this instance of Diags + */ +void +Diags::setup_diagslog(BaseLogFile *blf) +{ + diags_log = blf; + if (!diags_log) + return; + + // get file stream from BaseLogFile filedes + if (blf->open_file() == BaseLogFile::LOG_FILE_NO_ERROR) { + if (blf->m_fp) { + int status; + status = setvbuf(blf->m_fp, NULL, _IOLBF, 512); + if (status != 0) { + log_log_error("Could not setvbuf() for %s\n", blf->get_name()); + blf->close_file(); + delete blf; + diags_log = NULL; + } + } else { + log_log_error("Could not open diags log file: %s\n", strerror(errno)); + } + } + log_log_trace("Exiting setup_diagslog, name=%s, this=%p\n", blf->get_name(), this); +} + +void +Diags::config_roll_diagslog(RollingEnabledValues re, int ri, int rs) +{ + diagslog_rolling_enabled = re; + diagslog_rolling_interval = ri; + diagslog_rolling_size = rs; +} + +void +Diags::config_roll_outputlog(RollingEnabledValues re, int ri, int rs) +{ + outputlog_rolling_enabled = re; + outputlog_rolling_interval = ri; + outputlog_rolling_size = rs; +} + +/* + * Checks diags_log 's underlying file on disk and see if it needs to be rolled, + * and does so if necessary. + * + * This function will replace the current BaseLogFile object with a new one + * (if we choose to roll), as each BaseLogFile object logically represents one + * file on disk. + * + * Note that, however, cross process race conditions may still exist, especially with + * the metafile, and further work with flock() for fcntl() may still need to be done. + * + * Returns true if any logs rolled, false otherwise + */ +bool +Diags::should_roll_diagslog() +{ + bool ret_val = false; + + log_log_trace("should_roll_diagslog() was called\n"); + log_log_trace("rolling_enabled = %d, output_rolling_size = %d, output_rolling_interval = %d\n", diagslog_rolling_enabled, + diagslog_rolling_size, diagslog_rolling_interval); + log_log_trace("RollingEnabledValues::ROLL_ON_TIME = %d\n", RollingEnabledValues::ROLL_ON_TIME); + log_log_trace("time(0) - last_roll_time = %d\n", time(0) - diagslog_time_last_roll); + + // Roll diags_log if necessary + if (diags_log && diags_log->is_init()) { + if (diagslog_rolling_enabled == RollingEnabledValues::ROLL_ON_SIZE) { + struct stat buf; + fstat(fileno(diags_log->m_fp), &buf); + int size = buf.st_size; + if (diagslog_rolling_size != -1 && size >= (diagslog_rolling_size * BYTES_IN_MB)) { + fflush(diags_log->m_fp); + if (diags_log->roll()) { + char *oldname = ats_strdup(diags_log->get_name()); + log_log_trace("in should_roll_logs() for diags.log, oldname=%s\n", oldname); + delete diags_log; + setup_diagslog(new BaseLogFile(oldname)); + ats_free(oldname); + ret_val = true; + } + } + } else if (diagslog_rolling_enabled == RollingEnabledValues::ROLL_ON_TIME) { + time_t now = time(0); + if (diagslog_rolling_interval != -1 && (now - diagslog_time_last_roll) >= diagslog_rolling_interval) { + fflush(diags_log->m_fp); + if (diags_log->roll()) { + diagslog_time_last_roll = now; + char *oldname = ats_strdup(diags_log->get_name()); + log_log_trace("in should_roll_logs() for diags.log, oldname=%s\n", oldname); + delete diags_log; + setup_diagslog(new BaseLogFile(oldname)); + ats_free(oldname); + ret_val = true; + } + } + } + } + + return ret_val; +} + +/* + * Checks stdout_log and stderr_log if their underlying files on disk need to be + * rolled, and does so if necessary. + * + * This function will replace the current BaseLogFile objects with a + * new one (if we choose to roll), as each BaseLogFile object logically + * represents one file on disk + * + * Note that, however, cross process race conditions may still exist, especially with + * the metafile, and further work with flock() for fcntl() may still need to be done. + * + * Returns true if any logs rolled, false otherwise + */ +bool +Diags::should_roll_outputlog() +{ + bool ret_val = false; + bool need_consider_stderr = true; + + /* + log_log_trace("should_roll_outputlog() was called\n"); + log_log_trace("rolling_enabled = %d, output_rolling_size = %d, output_rolling_interval = %d\n", outputlog_rolling_enabled, + outputlog_rolling_size, outputlog_rolling_interval); + log_log_trace("RollingEnabledValues::ROLL_ON_TIME = %d\n", RollingEnabledValues::ROLL_ON_TIME); + log_log_trace("time(0) - last_roll_time = %d\n", time(0) - outputlog_time_last_roll); + log_log_trace("stdout_log = %p\n", stdout_log); + */ + + // Roll stdout_log if necessary + if (stdout_log && stdout_log->is_init()) { + if (outputlog_rolling_enabled == RollingEnabledValues::ROLL_ON_SIZE) { + struct stat buf; + fstat(fileno(stdout_log->m_fp), &buf); + int size = buf.st_size; + if (outputlog_rolling_size != -1 && size >= outputlog_rolling_size * BYTES_IN_MB) { + // since usually stdout and stderr are the same file on disk, we should just + // play it safe and just flush both BaseLogFiles + if (stderr_log && stderr_log->is_init()) + fflush(stderr_log->m_fp); + fflush(stdout_log->m_fp); + + if (stdout_log->roll()) { + char *oldname = ats_strdup(stdout_log->get_name()); + log_log_trace("in should_roll_logs(), oldname=%s\n", oldname); + set_stdout_output(oldname); + + // if stderr and stdout are redirected to the same place, we should + // update the stderr_log object as well + if (!strcmp(oldname, stderr_log->get_name())) { + log_log_trace("oldname == stderr_log->get_name()\n"); + set_stderr_output(oldname); + need_consider_stderr = false; + } + ats_free(oldname); + ret_val = true; + } + } + } else if (outputlog_rolling_enabled == RollingEnabledValues::ROLL_ON_TIME) { + time_t now = time(0); + if (outputlog_rolling_interval != -1 && (now - outputlog_time_last_roll) >= outputlog_rolling_interval) { + // since usually stdout and stderr are the same file on disk, we should just + // play it safe and just flush both BaseLogFiles + if (stderr_log && stderr_log->is_init()) + fflush(stderr_log->m_fp); + fflush(stdout_log->m_fp); + + if (stdout_log->roll()) { + outputlog_time_last_roll = now; + char *oldname = ats_strdup(stdout_log->get_name()); + log_log_trace("in should_roll_logs(), oldname=%s\n", oldname); + set_stdout_output(oldname); + + // if stderr and stdout are redirected to the same place, we should + // update the stderr_log object as well + if (!strcmp(oldname, stderr_log->get_name())) { + log_log_trace("oldname == stderr_log->get_name()\n"); + set_stderr_output(oldname); + need_consider_stderr = false; + } + ats_free(oldname); + ret_val = true; + } + } + } + } + + // This assertion has to be true since log rolling for traffic.out is only ever enabled + // (and useful) when traffic_server is NOT running in stand alone mode. If traffic_server + // is NOT running in stand alone mode, then stderr and stdout SHOULD ALWAYS be pointing + // to the same file (traffic.out). + // + // If for some reason, someone wants the feature to have stdout pointing to some file on + // disk, and stderr pointing to a different file on disk, and then also wants both files to + // rotate according to the (same || different) scheme, it would not be difficult to add + // some more config options in records.config and said feature into this function. + if (ret_val) + ink_assert(!need_consider_stderr); + + return ret_val; +} + +/* + * Binds stdout to _bind_stdout, provided that _bind_stdout != "". + * Also sets up a BaseLogFile for stdout. + * + * Returns true on binding and setup, false otherwise + * + * TODO make this a generic function (ie combine set_stdout_output and + * set_stderr_output + */ +bool +Diags::set_stdout_output(const char *_bind_stdout) +{ + if (strcmp(_bind_stdout, "") == 0) + return false; + + if (stdout_log) { + delete stdout_log; + stdout_log = NULL; + } + + // get root + ElevateAccess elevate(true); + + // create backing BaseLogFile for stdout + stdout_log = new BaseLogFile(_bind_stdout); + + // on any errors we quit + if (!stdout_log || stdout_log->open_file() != BaseLogFile::LOG_FILE_NO_ERROR) { + fprintf(stderr, "[Warning]: unable to open file=%s to bind stdout to\n", _bind_stdout); + delete stdout_log; + stdout_log = NULL; + return false; + } + if (!stdout_log->m_fp) { + fprintf(stderr, "[Warning]: file pointer for stdout %s = NULL\n", _bind_stdout); + delete stdout_log; + stdout_log = NULL; + return false; + } + + return rebind_stdout(fileno(stdout_log->m_fp)); +} + +/* + * Binds stderr to _bind_stderr, provided that _bind_stderr != "". + * Also sets up a BaseLogFile for stderr. + * + * Returns true on binding and setup, false otherwise + */ +bool +Diags::set_stderr_output(const char *_bind_stderr) +{ + if (strcmp(_bind_stderr, "") == 0) + return false; + + if (stderr_log) { + delete stderr_log; + stderr_log = NULL; + } + // get root + ElevateAccess elevate(true); + + // create backing BaseLogFile for stdout + stderr_log = new BaseLogFile(_bind_stderr); + + // on any errors we quit + if (!stderr_log || stderr_log->open_file() != BaseLogFile::LOG_FILE_NO_ERROR) { + fprintf(stderr, "[Warning]: unable to open file=%s to bind stderr to\n", _bind_stderr); + delete stderr_log; + stderr_log = NULL; + return false; + } + if (!stderr_log->m_fp) { + fprintf(stderr, "[Warning]: file pointer for stderr %s = NULL\n", _bind_stderr); + delete stderr_log; + stderr_log = NULL; + return false; + } + + return rebind_stderr(fileno(stderr_log->m_fp)); +} + +/* + * Helper function that rebinds stdout to specified file descriptor + * + * Returns true on success, false otherwise + */ +bool +Diags::rebind_stdout(int new_fd) +{ + if (new_fd < 0) + fprintf(stdout, "[Warning]: TS unable to bind stdout to new file descriptor=%d", new_fd); + else { + dup2(new_fd, STDOUT_FILENO); + return true; + } + return false; +} + +/* + * Helper function that rebinds stderr to specified file descriptor + * + * Returns true on success, false otherwise + */ +bool +Diags::rebind_stderr(int new_fd) +{ + if (new_fd < 0) + fprintf(stdout, "[Warning]: TS unable to bind stderr to new file descriptor=%d", new_fd); + else { + dup2(new_fd, STDERR_FILENO); + return true; + } + return false; +} diff --git a/lib/ts/Diags.h b/lib/ts/Diags.h index afe66bcda40..cebad82a0d6 100644 --- a/lib/ts/Diags.h +++ b/lib/ts/Diags.h @@ -36,12 +36,14 @@ #define __DIAGS_H___ #include -#include "ts/ink_error.h" -#include "ts/ink_mutex.h" -#include "ts/Regex.h" -#include "ts/ink_apidefs.h" +#include "ink_error.h" +#include "ink_mutex.h" +#include "Regex.h" +#include "ink_apidefs.h" +#include "BaseLogFile.h" #define DIAGS_MAGIC 0x12345678 +#define BYTES_IN_MB 1000000 class Diags; @@ -71,6 +73,8 @@ typedef enum { // do not renumber --- used as array index DL_Undefined // must be last, used for size! } DiagsLevel; +enum RollingEnabledValues { NO_ROLLING = 0, ROLL_ON_TIME, ROLL_ON_SIZE, INVALID_ROLLING_VALUE }; + #define DiagsLevel_Count DL_Undefined #define DiagsLevel_IsTerminal(_l) (((_l) >= DL_Fatal) && ((_l) < DL_Undefined)) @@ -145,10 +149,13 @@ class SrcLoc class Diags { public: - Diags(const char *base_debug_tags, const char *base_action_tags, FILE *_diags_log_fp = NULL); + Diags(const char *base_debug_tags, const char *base_action_tags, BaseLogFile *_diags_log); ~Diags(); - FILE *diags_log_fp; + BaseLogFile *diags_log; + BaseLogFile *stdout_log; + BaseLogFile *stderr_log; + const unsigned int magic; volatile DiagsConfigState config; int show_location; @@ -239,13 +246,38 @@ class Diags void deactivate_all(DiagsTagType mode = DiagsTagType_Debug); + void config_roll_diagslog(RollingEnabledValues re, int ri, int rs); + void config_roll_outputlog(RollingEnabledValues re, int ri, int rs); + bool should_roll_diagslog(); + bool should_roll_outputlog(); + + bool set_stdout_output(const char *_bind_stdout); + bool set_stderr_output(const char *_bind_stderr); + const char *base_debug_tags; // internal copy of default debug tags const char *base_action_tags; // internal copy of default action tags private: mutable ink_mutex tag_table_lock; // prevents reconfig/read races + mutable ink_mutex rotate_lock; // prevents rotation races DFA *activated_tags[2]; // 1 table for debug, 1 for action + + // log rotation variables + RollingEnabledValues outputlog_rolling_enabled; + int outputlog_rolling_size; + int outputlog_rolling_interval; + RollingEnabledValues diagslog_rolling_enabled; + int diagslog_rolling_interval; + int diagslog_rolling_size; + time_t start_time; // time since Diags was constructed + time_t outputlog_time_last_roll; + time_t diagslog_time_last_roll; + + + void setup_diagslog(BaseLogFile *blf); + bool rebind_stdout(int new_fd); + bool rebind_stderr(int new_fd); void lock() const { @@ -310,7 +342,7 @@ dummy_debug(const char *tag, const char *fmt, ...) diags->log(tag, DTA(DL_Diag), __VA_ARGS__) #define Debug(tag, ...) \ if (unlikely(diags->on())) \ - diags->log(tag, DTA(DL_Debug), __VA_ARGS__) + diags->log(tag, DTA(DL_Debug), __VA_ARGS__); #define DiagSpecific(flag, tag, ...) \ if (unlikely(diags->on())) \ flag ? diags->print(tag, DTA(DL_Diag), __VA_ARGS__) : diags->log(tag, DTA(DL_Diag), __VA_ARGS__) diff --git a/lib/ts/Makefile.am b/lib/ts/Makefile.am index dde1643fbfd..46ddda5f83b 100644 --- a/lib/ts/Makefile.am +++ b/lib/ts/Makefile.am @@ -43,6 +43,8 @@ libtsutil_la_SOURCES = \ Allocator.h \ Arena.cc \ Arena.h \ + BaseLogFile.cc \ + BaseLogFile.h \ Bitops.cc \ Bitops.h \ ConsistentHash.cc \ diff --git a/lib/ts/ink_file.cc b/lib/ts/ink_file.cc index 5e69d46107e..dafaf4b195c 100644 --- a/lib/ts/ink_file.cc +++ b/lib/ts/ink_file.cc @@ -510,3 +510,40 @@ ink_file_namemax(const char *path) return 255; #endif } + +int +ink_fileperm_parse(const char *perms) +{ + if (perms && strlen(perms) == 9) { + int re = 0; + char *c = (char *)perms; + if (*c == 'r') + re |= S_IRUSR; + c++; + if (*c == 'w') + re |= S_IWUSR; + c++; + if (*c == 'x') + re |= S_IXUSR; + c++; + if (*c == 'r') + re |= S_IRGRP; + c++; + if (*c == 'w') + re |= S_IWGRP; + c++; + if (*c == 'x') + re |= S_IXGRP; + c++; + if (*c == 'r') + re |= S_IROTH; + c++; + if (*c == 'w') + re |= S_IWOTH; + c++; + if (*c == 'x') + re |= S_IXOTH; + return re; + } + return -1; +} diff --git a/lib/ts/ink_file.h b/lib/ts/ink_file.h index 89b91aa826e..1150e75a5bc 100644 --- a/lib/ts/ink_file.h +++ b/lib/ts/ink_file.h @@ -118,6 +118,14 @@ bool ink_file_get_geometry(int fd, ink_device_geometry &geometry); // Return the value of pathconf(path, _PC_NAME_MAX), or the closest approximation. size_t ink_file_namemax(const char *path); +/** + Parses the given string for file permissions + Ownership of string parameter is NOT passed + Returns an integer bit field on success + Returns -1 on failure + */ +int ink_fileperm_parse(const char *perms); + // Is the given path "."? static inline bool isdot(const char *path) diff --git a/lib/ts/signals.cc b/lib/ts/signals.cc index 6cf664de326..93d6a2d3da7 100644 --- a/lib/ts/signals.cc +++ b/lib/ts/signals.cc @@ -69,6 +69,7 @@ check_signals(signal_handler_t handler) signal_check_handler(SIGTERM, handler); signal_check_handler(SIGINT, handler); signal_check_handler(SIGUSR1, handler); + signal_check_handler(SIGUSR2, handler); } static void diff --git a/lib/ts/test_X509HostnameValidator.cc b/lib/ts/test_X509HostnameValidator.cc index 5305bb0440d..c2e8a7d2e3a 100644 --- a/lib/ts/test_X509HostnameValidator.cc +++ b/lib/ts/test_X509HostnameValidator.cc @@ -174,7 +174,8 @@ REGRESSION_TEST(middle_label_match)(RegressionTest *t, int /* atype ATS_UNUSED * int main(int /* argc ATS_UNUSED */, const char ** /* argv ATS_UNUSED */) { - diags = new Diags(NULL, NULL, stdout); + BaseLogFile *blf = new BaseLogFile("stdout"); + diags = new Diags(NULL, NULL, blf); res_track_memory = 1; SSL_library_init(); diff --git a/mgmt/RecordsConfig.cc b/mgmt/RecordsConfig.cc index 72e677fa8de..2c8cfa69e66 100644 --- a/mgmt/RecordsConfig.cc +++ b/mgmt/RecordsConfig.cc @@ -97,6 +97,13 @@ static const RecordElement RecordsConfig[] = {RECT_CONFIG, "proxy.config.output.logfile", RECD_STRING, "traffic.out", RECU_RESTART_TC, RR_REQUIRED, RECC_NULL, NULL, RECA_NULL} , + // traffic.out rotation, default is 0 (aka rolling turned off) to preserve compatibility + {RECT_CONFIG, "proxy.config.output.logfile.rolling_enabled", RECD_INT, "0", RECU_DYNAMIC, RR_NULL, RECC_INT, "[0-2]", RECA_NULL} + , + {RECT_CONFIG, "proxy.config.output.logfile.rolling_interval_sec", RECD_INT, "3600", RECU_DYNAMIC, RR_NULL, RECC_STR, "^[0-9]+$", RECA_NULL} + , + {RECT_CONFIG, "proxy.config.output.logfile.rolling_size_mb", RECD_INT, "10", RECU_DYNAMIC, RR_NULL, RECC_STR, "^0*[1-9][0-9]*$", RECA_NULL} + , {RECT_CONFIG, "proxy.config.snapshot_dir", RECD_STRING, "snapshots", RECU_NULL, RR_REQUIRED, RECC_NULL, NULL, RECA_NULL} , //# 0 = disable @@ -214,6 +221,13 @@ static const RecordElement RecordsConfig[] = , {RECT_CONFIG, "proxy.config.diags.output.emergency", RECD_STRING, "SL", RECU_NULL, RR_NULL, RECC_NULL, NULL, RECA_NULL} , + // diags.log rotation, default is 0 (aka rolling turned off) to preserve compatibility + {RECT_CONFIG, "proxy.config.diags.logfile.rolling_enabled", RECD_INT, "0", RECU_DYNAMIC, RR_NULL, RECC_INT, "[0-2]", RECA_NULL} + , + {RECT_CONFIG, "proxy.config.diags.logfile.rolling_interval_sec", RECD_INT, "3600", RECU_DYNAMIC, RR_NULL, RECC_STR, "^[0-9]+$", RECA_NULL} + , + {RECT_CONFIG, "proxy.config.diags.logfile.rolling_size_mb", RECD_INT, "10", RECU_DYNAMIC, RR_NULL, RECC_STR, "^0*[1-9][0-9]*$", RECA_NULL} + , //############################################################################## //# diff --git a/proxy/Main.cc b/proxy/Main.cc index c517af396d3..16465a75490 100644 --- a/proxy/Main.cc +++ b/proxy/Main.cc @@ -124,6 +124,10 @@ static void *mgmt_restart_shutdown_callback(void *, char *, int data_len); static void *mgmt_storage_device_cmd_callback(void *x, char *data, int len); static void init_ssl_ctx_callback(void *ctx, bool server); +// XXX rename these to be more descriptive +void stdout_log_callback(void *); +void stderr_log_callback(void *); + static int num_of_net_threads = ink_number_of_processors(); static int num_of_udp_threads = 0; static int num_accept_threads = 0; @@ -153,6 +157,8 @@ char cluster_host[MAXDNAME + 1] = DEFAULT_CLUSTER_HOST; static char command_string[512] = ""; static char conf_dir[512] = ""; int remote_management_flag = DEFAULT_REMOTE_MANAGEMENT_FLAG; +static char bind_stdout[512] = DEFAULT_BIND_STDOUT; +static char bind_stderr[512] = DEFAULT_BIND_STDERR; static char error_tags[1024] = ""; static char action_tags[1024] = ""; @@ -165,6 +171,7 @@ static int cmd_line_dprintf_level = 0; // default debug output level from ink_dp static int poll_timeout = -1; // No value set. static volatile bool sigusr1_received = false; +static volatile bool sigusr2_received = false; // 1: delay listen, wait for cache. // 0: Do not delay, start listen ASAP. @@ -199,6 +206,8 @@ static const ArgumentDescription argument_descriptions[] = { {"conf_dir", 'D', "config dir to verify", "S511", &conf_dir, "PROXY_SYS_CONFIG_DIR", NULL}, {"clear_hostdb", 'k', "Clear HostDB on Startup", "F", &auto_clear_hostdb_flag, "PROXY_CLEAR_HOSTDB", NULL}, {"clear_cache", 'K', "Clear Cache on Startup", "F", &cacheProcessor.auto_clear_flag, "PROXY_CLEAR_CACHE", NULL}, + {"bind_stdout", '-', "Regular file to bind stdout to", "S512", &bind_stdout, "PROXY_BIND_STDOUT", NULL}, + {"bind_stderr", '-', "Regular file to bind stderr to", "S512", &bind_stderr, "PROXY_BIND_STDERR", NULL}, #if defined(linux) {"read_core", 'c', "Read Core file", "S255", &core_file, NULL, NULL}, #endif @@ -248,6 +257,12 @@ class SignalContinuation : public Continuation fastmemsnap += fmdelta; #endif snap = now; + } else if (sigusr2_received) { + sigusr2_received = false; + Debug("log", "received SIGUSR2, reloading traffic.outl\n"); + // reload output logfile (file is usually called traffic.out) + diags->set_stdout_output(bind_stdout); + diags->set_stderr_output(bind_stderr); } return EVENT_CONT; @@ -295,6 +310,37 @@ class TrackerContinuation : public Continuation } }; +// This continuation is used to periodically check on diags.log, and rotate +// the logs if necessary +class DiagsLogContinuation : public Continuation +{ +public: + DiagsLogContinuation() : Continuation(new_ProxyMutex()) { SET_HANDLER(&DiagsLogContinuation::periodic); } + + int + periodic(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */) + { + Debug("log", "in DiagsLogContinuation, checking on diags.log"); + + // First, let us update the rolling config values for diagslog. We + // do not need to update the config values for outputlog because + // traffic_server never actually rotates outputlog. outputlog is always + // rotated in traffic_manager. The reason being is that it is difficult + // to send a notification from TS to TM, informing TM that outputlog has + // been rolled. It is much easier sending a notification (in the form + // of SIGUSR2) from TM -> TS. + int diags_log_roll_int = (int)REC_ConfigReadInteger("proxy.config.diags.logfile.rolling_interval_sec"); + int diags_log_roll_size = (int)REC_ConfigReadInteger("proxy.config.diags.logfile.rolling_size_mb"); + int diags_log_roll_enable = (int)REC_ConfigReadInteger("proxy.config.diags.logfile.rolling_enabled"); + diags->config_roll_diagslog((RollingEnabledValues)diags_log_roll_enable, diags_log_roll_int, diags_log_roll_size); + + if (diags->should_roll_diagslog()) { + Note("Rolled %s", DIAGS_LOG_FILENAME); + } + return EVENT_CONT; + } +}; + static int init_memory_tracker(const char *config_var, RecDataT /* type ATS_UNUSED */, RecData data, void * /* cookie ATS_UNUSED */) { @@ -328,6 +374,9 @@ proxy_signal_handler(int signo, siginfo_t *info, void *) case SIGUSR1: sigusr1_received = true; return; + case SIGUSR2: + sigusr2_received = true; + return; case SIGHUP: return; } @@ -1367,6 +1416,41 @@ change_uid_gid(const char *user) #endif } +/* + * Binds stdout and stderr to files specified by the parameters + * + * On failure to bind, emits a warning and whatever is being bound + * just isn't bound + */ +void +bind_outputs(const char *_bind_stdout, const char *_bind_stderr) +{ + ElevateAccess a(true); + int log_fd; + if (strcmp(_bind_stdout, "") != 0) { + Debug("log", "binding stdout to %s", _bind_stdout); + log_fd = open(_bind_stdout, O_WRONLY | O_APPEND | O_CREAT, 0644); + if (log_fd < 0) { + fprintf(stdout, "[Warning]: TS unable to open log file \"%s\" [%d '%s']\n", _bind_stdout, errno, strerror(errno)); + } else { + Debug("log", "duping stdout"); + dup2(log_fd, STDOUT_FILENO); + close(log_fd); + } + } + if (strcmp(_bind_stderr, "") != 0) { + Debug("log", "binding stderr to %s", _bind_stderr); + log_fd = open(_bind_stderr, O_WRONLY | O_APPEND | O_CREAT, 0644); + if (log_fd < 0) { + fprintf(stdout, "[Warning]: TS unable to open log file \"%s\" [%d '%s']\n", _bind_stderr, errno, strerror(errno)); + } else { + Debug("log", "duping stderr"); + dup2(log_fd, STDERR_FILENO); + close(log_fd); + } + } +} + // // Main // @@ -1401,6 +1485,11 @@ main(int /* argc ATS_UNUSED */, const char **argv) command_index = find_cmd_index(command_string); command_valid = command_flag && command_index >= 0; + // Bind stdout and stderr to specified switches + // Still needed despite the set_std{err,out}_output() calls later since there are + // fprintf's before those calls + bind_outputs(bind_stdout, bind_stderr); + // Specific validity checks. if (*conf_dir && command_index != find_cmd_index(CMD_VERIFY_CONFIG)) { fprintf(stderr, "-D option can only be used with the %s command\n", CMD_VERIFY_CONFIG); @@ -1427,6 +1516,8 @@ main(int /* argc ATS_UNUSED */, const char **argv) diagsConfig = new DiagsConfig(DIAGS_LOG_FILENAME, error_tags, action_tags, false); diags = diagsConfig->diags; diags->prefix_str = "Server "; + diags->set_stdout_output(bind_stdout); + diags->set_stderr_output(bind_stderr); if (is_debug_tag_set("diags")) diags->dump(); @@ -1507,6 +1598,8 @@ main(int /* argc ATS_UNUSED */, const char **argv) diags = diagsConfig->diags; RecSetDiags(diags); diags->prefix_str = "Server "; + diags->set_stdout_output(bind_stdout); + diags->set_stderr_output(bind_stderr); if (is_debug_tag_set("diags")) diags->dump(); @@ -1634,6 +1727,7 @@ main(int /* argc ATS_UNUSED */, const char **argv) } eventProcessor.schedule_every(new SignalContinuation, HRTIME_MSECOND * 500, ET_CALL); + eventProcessor.schedule_every(new DiagsLogContinuation, HRTIME_SECOND, ET_TASK); REC_RegisterConfigUpdateFunc("proxy.config.dump_mem_info_frequency", init_memory_tracker, NULL); init_memory_tracker(NULL, RECD_NULL, RecData(), NULL); diff --git a/proxy/Main.h b/proxy/Main.h index b2ae0adb44c..5e83bbd0a09 100644 --- a/proxy/Main.h +++ b/proxy/Main.h @@ -40,6 +40,8 @@ #define DEFAULT_LOCAL_STATE_DIRECTORY "var/trafficserver" #define DEFAULT_SYSTEM_CONFIG_DIRECTORY "etc/trafficserver" #define DEFAULT_LOG_DIRECTORY "var/log/trafficserver" +#define DEFAULT_BIND_STDOUT "" +#define DEFAULT_BIND_STDERR "" // // Global Data diff --git a/proxy/Makefile.am b/proxy/Makefile.am index 01602946c3e..7e228c86471 100644 --- a/proxy/Makefile.am +++ b/proxy/Makefile.am @@ -47,6 +47,7 @@ AM_CPPFLAGS = \ -I$(top_srcdir)/mgmt/utils \ -I$(top_srcdir)/proxy/api/ts \ -I$(top_srcdir)/lib \ + -I$(top_srcdir)/lib/ts \ @OPENSSL_INCLUDES@ # NOTE: it is safe to use AM_LDFLAGS here because we are only building executables. If we start diff --git a/proxy/logging/Log.cc b/proxy/logging/Log.cc index 4f919e7b50b..2bbdbd77ad3 100644 --- a/proxy/logging/Log.cc +++ b/proxy/logging/Log.cc @@ -1223,7 +1223,7 @@ Log::flush_thread_main(void * /* args ATS_UNUSED */) break; } - len = ::write(logfile->m_fd, &buf[bytes_written], total_bytes - bytes_written); + len = ::write(logfile->get_fd(), &buf[bytes_written], total_bytes - bytes_written); if (len < 0) { Error("Failed to write log to %s: [tried %d, wrote %d, %s]", logfile->get_name(), total_bytes - bytes_written, bytes_written, strerror(errno)); @@ -1232,12 +1232,14 @@ Log::flush_thread_main(void * /* args ATS_UNUSED */) total_bytes - bytes_written); break; } + Debug("log", "Successfully wrote some stuff to %s", logfile->get_name()); bytes_written += len; } RecIncrRawStat(log_rsb, mutex->thread_holding, log_stat_bytes_written_to_disk_stat, bytes_written); - ink_atomic_increment(&logfile->m_bytes_written, bytes_written); + if (logfile->m_log) + ink_atomic_increment(&logfile->m_log->m_bytes_written, bytes_written); delete fdata; } diff --git a/proxy/logging/LogConfig.cc b/proxy/logging/LogConfig.cc index f9b1c0b7c95..402a4f35176 100644 --- a/proxy/logging/LogConfig.cc +++ b/proxy/logging/LogConfig.cc @@ -149,39 +149,11 @@ LogConfig::read_configuration_variables() max_space_mb_headroom = val; } - // TODO: We should mover this "parser" to lib/ts ptr = REC_ConfigReadString("proxy.config.log.logfile_perm"); - if (ptr && strlen(ptr) == 9) { - logfile_perm = 0; - char *c = ptr; - if (*c == 'r') - logfile_perm |= S_IRUSR; - c++; - if (*c == 'w') - logfile_perm |= S_IWUSR; - c++; - if (*c == 'x') - logfile_perm |= S_IXUSR; - c++; - if (*c == 'r') - logfile_perm |= S_IRGRP; - c++; - if (*c == 'w') - logfile_perm |= S_IWGRP; - c++; - if (*c == 'x') - logfile_perm |= S_IXGRP; - c++; - if (*c == 'r') - logfile_perm |= S_IROTH; - c++; - if (*c == 'w') - logfile_perm |= S_IWOTH; - c++; - if (*c == 'x') - logfile_perm |= S_IXOTH; - ats_free(ptr); - } + int logfile_perm_parsed = ink_fileperm_parse(ptr); + if (logfile_perm_parsed != -1) + logfile_perm = logfile_perm_parsed; + ats_free(ptr); ptr = REC_ConfigReadString("proxy.config.log.hostname"); if (ptr != NULL) { @@ -792,7 +764,7 @@ LogConfig::update_space_used() if (sret != -1 && S_ISREG(sbuf.st_mode)) { total_space_used += (int64_t)sbuf.st_size; - if (auto_delete_rolled_files && LogFile::rolled_logfile(m_dir_entry->d_name) && candidate_count < MAX_CANDIDATES) { + if (auto_delete_rolled_files && BaseLogFile::rolled_logfile(m_dir_entry->d_name) && candidate_count < MAX_CANDIDATES) { // // then add this entry to the candidate list // diff --git a/proxy/logging/LogFile.cc b/proxy/logging/LogFile.cc index bf8ef3ec202..feb4b578d76 100644 --- a/proxy/logging/LogFile.cc +++ b/proxy/logging/LogFile.cc @@ -42,6 +42,7 @@ #include "I_Machine.h" #include "LogSock.h" +#include "BaseLogFile.h" #include "LogField.h" #include "LogFilter.h" #include "LogFormat.h" @@ -62,15 +63,17 @@ LogFile::LogFile(const char *name, const char *header, LogFileFormat format, uint64_t signature, size_t ascii_buffer_size, size_t max_line_size) - : m_file_format(format), m_name(ats_strdup(name)), m_header(ats_strdup(header)), m_signature(signature), m_meta_info(NULL), + : m_file_format(format), m_name(ats_strdup(name)), m_header(ats_strdup(header)), m_signature(signature), m_max_line_size(max_line_size) { - delete m_meta_info; - m_meta_info = NULL; + if (m_file_format != LOG_FILE_PIPE) { + m_log = new BaseLogFile(name, m_signature); + m_log->set_hostname(Machine::instance()->hostname); + } else { + m_log = NULL; + } + m_fd = -1; - m_start_time = 0L; - m_end_time = 0L; - m_bytes_written = 0; m_ascii_buffer_size = (ascii_buffer_size < max_line_size ? max_line_size : ascii_buffer_size); Debug("log-file", "exiting LogFile constructor, m_name=%s, this=%p", m_name, this); @@ -84,11 +87,17 @@ LogFile::LogFile(const char *name, const char *header, LogFileFormat format, uin LogFile::LogFile(const LogFile ©) : m_file_format(copy.m_file_format), m_name(ats_strdup(copy.m_name)), m_header(ats_strdup(copy.m_header)), - m_signature(copy.m_signature), m_meta_info(NULL), m_ascii_buffer_size(copy.m_ascii_buffer_size), - m_max_line_size(copy.m_max_line_size), m_fd(-1), m_start_time(0L), m_end_time(0L), m_bytes_written(0) + m_signature(copy.m_signature), m_ascii_buffer_size(copy.m_ascii_buffer_size), m_max_line_size(copy.m_max_line_size), + m_fd(copy.m_fd) { ink_release_assert(m_ascii_buffer_size >= m_max_line_size); + if (copy.m_log) { + m_log = new BaseLogFile(*(copy.m_log)); + } else { + m_log = NULL; + } + Debug("log-file", "exiting LogFile copy constructor, m_name=%s, this=%p", m_name, this); } /*------------------------------------------------------------------------- @@ -98,27 +107,12 @@ LogFile::LogFile(const LogFile ©) LogFile::~LogFile() { Debug("log-file", "entering LogFile destructor, this=%p", this); - close_file(); - - ats_free(m_name); + delete m_log; ats_free(m_header); - delete m_meta_info; + ats_free(m_name); Debug("log-file", "exiting LogFile destructor, this=%p", this); } -/*------------------------------------------------------------------------- - LogFile::exists - - Returns true if the logfile already exists; false otherwise. - -------------------------------------------------------------------------*/ - -bool -LogFile::exists(const char *pathname) -{ - ink_assert(pathname != NULL); - return (pathname && ::access(pathname, F_OK) == 0); -} - /*------------------------------------------------------------------------- LogFile::change_name -------------------------------------------------------------------------*/ @@ -151,37 +145,15 @@ LogFile::change_header(const char *header) int LogFile::open_file() { + // is_open() takes into account if we're using BaseLogFile or a naked fd if (is_open()) { return LOG_FILE_NO_ERROR; } - if (m_name && !strcmp(m_name, "stdout")) { - m_fd = STDOUT_FILENO; - return LOG_FILE_NO_ERROR; - } - // - // Check to see if the file exists BEFORE we try to open it, since - // opening it will also create it. - // - bool file_exists = LogFile::exists(m_name); - - if (file_exists) { - if (!m_meta_info) { - // This object must be fresh since it has not built its MetaInfo - // so we create a new MetaInfo object that will read right away - // (in the constructor) the corresponding metafile - // - m_meta_info = new MetaInfo(m_name); - } - } else { - // The log file does not exist, so we create a new MetaInfo object - // which will save itself to disk right away (in the constructor) - m_meta_info = new MetaInfo(m_name, LogUtils::timestamp(), m_signature); - } - - int flags, perms; + bool file_exists = BaseLogFile::exists(m_name); if (m_file_format == LOG_FILE_PIPE) { + // setup pipe if (mkfifo(m_name, S_IRUSR | S_IWUSR) < 0) { if (errno != EEXIST) { Error("Could not create named pipe %s for logging: %s", m_name, strerror(errno)); @@ -190,39 +162,32 @@ LogFile::open_file() } else { Debug("log-file", "Created named pipe %s for logging", m_name); } - flags = O_WRONLY | O_NDELAY; - perms = 0; - } else { - flags = O_WRONLY | O_APPEND | O_CREAT; - perms = Log::config->logfile_perm; - } - - Debug("log-file", "attempting to open %s", m_name); - m_fd = ::open(m_name, flags, perms); - if (m_fd < 0) { - // if error happened because no process is reading the pipe don't - // complain, otherwise issue an error message - // - if (errno != ENXIO) { - Error("Error opening log file %s: %s", m_name, strerror(errno)); + // now open the pipe + Debug("log-file", "attempting to open pipe %s", m_name); + m_fd = ::open(m_name, O_WRONLY | O_NDELAY, 0); + if (m_fd < 0) { + Debug("log-file", "no readers for pipe %s", m_name); + return LOG_FILE_NO_PIPE_READERS; + } + } else { + if (m_log) { + int status = m_log->open_file(Log::config->logfile_perm); + if (status == BaseLogFile::LOG_FILE_COULD_NOT_OPEN_FILE) + return LOG_FILE_COULD_NOT_OPEN_FILE; + } else { return LOG_FILE_COULD_NOT_OPEN_FILE; } - Debug("log-file", "no readers for pipe %s", m_name); - return LOG_FILE_NO_PIPE_READERS; } int e = do_filesystem_checks(); if (e != 0) { m_fd = -1; // reset to error condition + delete m_log; + m_log = NULL; return LOG_FILE_FILESYSTEM_CHECKS_FAILED; } - // set m_bytes_written to force the rolling based on filesize. - m_bytes_written = lseek(m_fd, 0, SEEK_CUR); - - Debug("log-file", "LogFile %s is now open (fd=%d)", m_name, m_fd); - // // If we've opened the file and it didn't already exist, then this is a // "new" file and we need to make some initializations. This is the @@ -230,14 +195,15 @@ LogFile::open_file() // file. // if (!file_exists) { - if (m_file_format != LOG_FILE_BINARY && m_header != NULL) { + if (m_file_format != LOG_FILE_BINARY && m_header && m_log) { Debug("log-file", "writing header to LogFile %s", m_name); - writeln(m_header, strlen(m_header), m_fd, m_name); + writeln(m_header, strlen(m_header), fileno(m_log->m_fp), m_name); } } RecIncrRawStat(log_rsb, this_thread()->mutex->thread_holding, log_stat_log_files_open_stat, 1); + Debug("log", "exiting LogFile::open_file(), file=%s presumably open", m_name); return LOG_FILE_NO_ERROR; } @@ -251,171 +217,36 @@ void LogFile::close_file() { if (is_open()) { - ::close(m_fd); - Debug("log-file", "LogFile %s (fd=%d) is closed", m_name, m_fd); - m_fd = -1; - - RecIncrRawStat(log_rsb, this_thread()->mutex->thread_holding, log_stat_log_files_open_stat, -1); - } -} - -/*------------------------------------------------------------------------- - LogFile::rolled_logfile - - This function will return true if the given filename corresponds to a - rolled logfile. We make this determination based on the file extension. - -------------------------------------------------------------------------*/ - -bool -LogFile::rolled_logfile(char *path) -{ - const int target_len = (int)strlen(LOGFILE_ROLLED_EXTENSION); - int len = (int)strlen(path); - if (len > target_len) { - char *str = &path[len - target_len]; - if (!strcmp(str, LOGFILE_ROLLED_EXTENSION)) { - return true; + if (m_file_format == LOG_FILE_PIPE) { + ::close(m_fd); + Debug("log-file", "LogFile %s (fd=%d) is closed", m_name, m_fd); + m_fd = -1; + } else if (m_log) { + m_log->close_file(); + Debug("log-file", "LogFile %s is closed", m_log->get_name()); + m_log = NULL; + } else { + Warning("LogFile %s is open but was not closed", m_name); } } - return false; + + RecIncrRawStat(log_rsb, this_thread()->mutex->thread_holding, log_stat_log_files_open_stat, -1); } /*------------------------------------------------------------------------- - LogFile::roll - - This function is called by a LogObject to roll its files. The - tricky part to this routine is in coming up with the new file name, - which contains the bounding timestamp interval for the entries - within the file. - - Under normal operating conditions, this LogFile object was in existence - for all writes to the file. In this case, the LogFile members m_start_time - and m_end_time will have the starting and ending times for the actual - entries written to the file. - - On restart situations, it is possible to re-open an existing logfile, - which means that the m_start_time variable will be later than the actual - entries recorded in the file. In this case, we'll use the creation time - of the file, which should be recorded in the meta-information located on - disk. - - If we can't use the meta-file, either because it's not there or because - it's not valid, then we'll use timestamp 0 (Jan 1, 1970) as the starting - bound. - - Return 1 if file rolled, 0 otherwise - -------------------------------------------------------------------------*/ - + * LogFile::roll + * This function is called by a LogObject to roll its files. + * + * Return 1 if file rolled, 0 otherwise +-------------------------------------------------------------------------*/ int LogFile::roll(long interval_start, long interval_end) { - // - // First, let's see if a roll is even needed. - // - if (m_name == NULL || !LogFile::exists(m_name)) { - Debug("log-file", "Roll not needed for %s; file doesn't exist", (m_name) ? m_name : "no_name"); - return 0; - } - // Read meta info if needed (if file was not opened) - // - if (!m_meta_info) { - m_meta_info = new MetaInfo(m_name); + if (m_log) { + return m_log->roll(interval_start, interval_end); } - // - // Create the new file name, which consists of a timestamp and rolled - // extension added to the previous file name. The timestamp format is - // ".%Y%m%d.%Hh%Mm%Ss-%Y%m%d.%Hh%Mm%Ss", where the two date/time values - // represent the starting and ending times for entries in the rolled - // log file. In addition, we add the hostname. So, the entire rolled - // format is something like: - // - // "squid.log.mymachine.19980712.12h00m00s-19980713.12h00m00s.old" - // - char roll_name[MAXPATHLEN]; - char start_time_ext[64]; - char end_time_ext[64]; - time_t start, end; - // - // Make sure the file is closed so we don't leak any descriptors. - // - close_file(); - - // - // Start with conservative values for the start and end bounds, then - // try to refine. - // - start = 0L; - end = (interval_end >= m_end_time) ? interval_end : m_end_time; - - if (m_meta_info->data_from_metafile()) { - // - // If the metadata came from the metafile, this means that - // the file was preexisting, so we can't use m_start_time for - // our starting bounds. Instead, we'll try to use the file - // creation time stored in the metafile (if it's valid and we can - // read it). If all else fails, we'll use 0 for the start time. - // - m_meta_info->get_creation_time(&start); - } else { - // - // The logfile was not preexisting (normal case), so we'll use - // earlier of the interval start time and the m_start_time. - // - // note that m_start_time is not the time of the first - // transaction, but the time of the creation of the first log - // buffer used by the file. These times may be different, - // especially under light load, and using the m_start_time may - // produce overlapping filenames (the problem is that we have - // no easy way of keeping track of the timestamp of the first - // transaction - // - start = (m_start_time < interval_start) ? m_start_time : interval_start; - } - - // - // Now that we have our timestamp values, convert them to the proper - // timestamp formats and create the rolled file name. - // - LogUtils::timestamp_to_str((long)start, start_time_ext, 64); - LogUtils::timestamp_to_str((long)end, end_time_ext, 64); - snprintf(roll_name, MAXPATHLEN, "%s%s%s.%s-%s%s", m_name, LOGFILE_SEPARATOR_STRING, Machine::instance()->hostname, start_time_ext, - end_time_ext, LOGFILE_ROLLED_EXTENSION); - - // - // It may be possible that the file we want to roll into already - // exists. If so, then we need to add a version tag to the rolled - // filename as well so that we don't clobber existing files. - // - - int version = 1; - while (LogFile::exists(roll_name)) { - Note("The rolled file %s already exists; adding version " - "tag %d to avoid clobbering the existing file.", - roll_name, version); - snprintf(roll_name, MAXPATHLEN, "%s%s%s.%s-%s.%d%s", m_name, LOGFILE_SEPARATOR_STRING, Machine::instance()->hostname, - start_time_ext, end_time_ext, version, LOGFILE_ROLLED_EXTENSION); - version++; - } - - // - // It's now safe to rename the file. - // - - if (::rename(m_name, roll_name) < 0) { - Warning("Traffic Server could not rename logfile %s to %s, error %d: " - "%s.", - m_name, roll_name, errno, strerror(errno)); - return 0; - } - // reset m_start_time - // - m_start_time = 0; - m_bytes_written = 0; - - Debug("log-file", "The logfile %s was rolled to %s.", m_name, roll_name); - - return 1; + return 0; } /*------------------------------------------------------------------------- @@ -452,9 +283,9 @@ LogFile::preproc_and_try_delete(LogBuffer *lb) // the low_timestamp from the given LogBuffer. Then, we always set the // end time to the high_timestamp, so it's always up to date. // - if (!m_start_time) - m_start_time = buffer_header->low_timestamp; - m_end_time = buffer_header->high_timestamp; + if (!m_log->m_start_time) + m_log->m_start_time = buffer_header->low_timestamp; + m_log->m_end_time = buffer_header->high_timestamp; if (m_file_format == LOG_FILE_BINARY) { // @@ -727,7 +558,7 @@ LogFile::check_fd() // attept to re-open it, which will create the file if it's not // there. // - if (m_name && !LogFile::exists(m_name)) { + if (m_name && !BaseLogFile::exists(m_name)) { close_file(); } stat_check_count = 0; @@ -754,115 +585,33 @@ LogFile::display(FILE *fd) fprintf(fd, "Logfile: %s, %s\n", get_name(), (is_open()) ? "file is open" : "file is not open"); } -/*************************************************************************** - LogFileList IS NOT USED -****************************************************************************/ - - -/**************************************************************************** - - MetaInfo methods - -*****************************************************************************/ - -void -MetaInfo::_build_name(const char *filename) +bool +LogFile::is_open() { - int i = -1, l = 0; - char c; - while (c = filename[l], c != 0) { - if (c == '/') { - i = l; - } - ++l; - } - - // 7 = 1 (dot at beginning) + 5 (".meta") + 1 (null terminating) - // - _filename = (char *)ats_malloc(l + 7); - - if (i < 0) { - ink_string_concatenate_strings(_filename, ".", filename, ".meta", NULL); - } else { - memcpy(_filename, filename, i + 1); - ink_string_concatenate_strings(&_filename[i + 1], ".", &filename[i + 1], ".meta", NULL); - } + if (m_file_format == LOG_FILE_PIPE) + return (m_fd >= 0); + else + return (m_log && m_log->is_open()); } -void -MetaInfo::_read_from_file() +/* + * Returns the fd of the entity (pipe or regular file ) that this object is + * representing + * + * Returns -1 on error, the correct fd otherwise + */ +int +LogFile::get_fd() { - _flags |= DATA_FROM_METAFILE; - int fd = open(_filename, O_RDONLY); - if (fd < 0) { - Warning("Could not open metafile %s for reading: %s", _filename, strerror(errno)); + if (m_file_format == LOG_FILE_PIPE) { + return m_fd; + } else if (m_log && m_log->m_fp) { + return fileno(m_log->m_fp); } else { - _flags |= FILE_OPEN_SUCCESSFUL; - SimpleTokenizer tok('=', SimpleTokenizer::OVERWRITE_INPUT_STRING); - int line_number = 1; - while (ink_file_fd_readline(fd, BUF_SIZE, _buffer) > 0) { - tok.setString(_buffer); - char *t = tok.getNext(); - if (t) { - if (strcmp(t, "creation_time") == 0) { - t = tok.getNext(); - if (t) { - _creation_time = (time_t)ink_atoi64(t); - _flags |= VALID_CREATION_TIME; - } - } else if (strcmp(t, "object_signature") == 0) { - t = tok.getNext(); - if (t) { - _log_object_signature = ink_atoi64(t); - _flags |= VALID_SIGNATURE; - Debug("log-meta", "MetaInfo::_read_from_file\n" - "\tfilename = %s\n" - "\tsignature string = %s\n" - "\tsignature value = %" PRIu64 "", - _filename, t, _log_object_signature); - } - } else if (line_number == 1) { - ink_release_assert(!"no panda support"); - } - } - ++line_number; - } - close(fd); + return -1; } } -void -MetaInfo::_write_to_file() -{ - int fd = open(_filename, O_WRONLY | O_CREAT | O_TRUNC, Log::config->logfile_perm); - if (fd < 0) { - Warning("Could not open metafile %s for writing: %s", _filename, strerror(errno)); - return; - } - - int n; - if (_flags & VALID_CREATION_TIME) { - n = snprintf(_buffer, BUF_SIZE, "creation_time = %lu\n", (unsigned long)_creation_time); - // TODO modify this runtime check so that it is not an assertion - ink_release_assert(n <= BUF_SIZE); - if (write(fd, _buffer, n) == -1) { - Warning("Could not write creation_time"); - } - } - - if (_flags & VALID_SIGNATURE) { - n = snprintf(_buffer, BUF_SIZE, "object_signature = %" PRIu64 "\n", _log_object_signature); - // TODO modify this runtime check so that it is not an assertion - ink_release_assert(n <= BUF_SIZE); - if (write(fd, _buffer, n) == -1) { - Warning("Could not write object_signaure"); - } - Debug("log-meta", "MetaInfo::_write_to_file\n" - "\tfilename = %s\n" - "\tsignature value = %" PRIu64 "\n" - "\tsignature string = %s", - _filename, _log_object_signature, _buffer); - } - - close(fd); -} +/*************************************************************************** + LogFileList IS NOT USED +****************************************************************************/ diff --git a/proxy/logging/LogFile.h b/proxy/logging/LogFile.h index 6c6e761147e..f935bb110e1 100644 --- a/proxy/logging/LogFile.h +++ b/proxy/logging/LogFile.h @@ -35,91 +35,8 @@ class LogSock; class LogBuffer; struct LogBufferHeader; class LogObject; - -#define LOGFILE_ROLLED_EXTENSION ".old" -#define LOGFILE_SEPARATOR_STRING "_" - -/*------------------------------------------------------------------------- - MetaInfo - - Meta information for LogFile - -------------------------------------------------------------------------*/ -class MetaInfo -{ -public: - enum { - DATA_FROM_METAFILE = 1, // metadata was read (or attempted to) - // from metafile - VALID_CREATION_TIME = 2, // creation time is valid - VALID_SIGNATURE = 4, // signature is valid - // (i.e., creation time only) - FILE_OPEN_SUCCESSFUL = 8 // metafile was opened successfully - }; - - enum { - BUF_SIZE = 640 // size of read/write buffer - }; - -private: - char *_filename; // the name of the meta file - time_t _creation_time; // file creation time - uint64_t _log_object_signature; // log object signature - int _flags; // metainfo status flags - char _buffer[BUF_SIZE]; // read/write buffer - - void _read_from_file(); - void _write_to_file(); - void _build_name(const char *filename); - -public: - MetaInfo(const char *filename) : _flags(0) - { - _build_name(filename); - _read_from_file(); - } - - MetaInfo(char *filename, time_t creation, uint64_t signature) - : _creation_time(creation), _log_object_signature(signature), _flags(VALID_CREATION_TIME | VALID_SIGNATURE) - { - _build_name(filename); - _write_to_file(); - } - - ~MetaInfo() { ats_free(_filename); } - - bool - get_creation_time(time_t *time) - { - if (_flags & VALID_CREATION_TIME) { - *time = _creation_time; - return true; - } else { - return false; - } - } - - bool - get_log_object_signature(uint64_t *signature) - { - if (_flags & VALID_SIGNATURE) { - *signature = _log_object_signature; - return true; - } else { - return false; - } - } - - bool - data_from_metafile() const - { - return (_flags & DATA_FROM_METAFILE ? true : false); - } - bool - file_open_successful() - { - return (_flags & FILE_OPEN_SUCCESSFUL ? true : false); - } -}; +class BaseLogFile; +class BaseMetaInfo; /*------------------------------------------------------------------------- LogFile @@ -168,8 +85,6 @@ class LogFile : public LogBufferSink, public RefCountObj static int write_ascii_logbuffer(LogBufferHeader *buffer_header, int fd, const char *path, const char *alt_format = NULL); int write_ascii_logbuffer3(LogBufferHeader *buffer_header, const char *alt_format = NULL); - static bool rolled_logfile(char *file); - static bool exists(const char *pathname); void display(FILE *fd = stdout); int open_file(); @@ -177,7 +92,12 @@ class LogFile : public LogBufferSink, public RefCountObj off_t get_size_bytes() const { - return m_file_format != LOG_FILE_PIPE ? m_bytes_written : 0; + if (m_file_format == LOG_FILE_PIPE) + return 0; + else if (m_log) + return m_log->get_size_bytes(); + else + return 0; }; int do_filesystem_checks() @@ -186,14 +106,10 @@ class LogFile : public LogBufferSink, public RefCountObj }; // TODO: this need to be tidy up when to redo the file checking public: - bool - is_open() - { - return (m_fd >= 0); - } + bool is_open(); void close_file(); - void check_fd(); + int get_fd(); static int writeln(char *data, int len, int fd, const char *path); public: @@ -203,18 +119,14 @@ class LogFile : public LogBufferSink, public RefCountObj char *m_name; public: + BaseLogFile *m_log; // BaseLogFile backs the actual file on disk char *m_header; uint64_t m_signature; // signature of log object stored - MetaInfo *m_meta_info; size_t m_ascii_buffer_size; // size of ascii buffer size_t m_max_line_size; // size of longest log line (record) - int m_fd; - long m_start_time; - long m_end_time; - volatile uint64_t m_bytes_written; - + int m_fd; // this could back m_log or a pipe, depending on the situation public: Link link; diff --git a/proxy/logging/LogObject.cc b/proxy/logging/LogObject.cc index d4a04d4c555..bb67a255c74 100644 --- a/proxy/logging/LogObject.cc +++ b/proxy/logging/LogObject.cc @@ -970,7 +970,7 @@ LogObjectManager::_solve_filename_conflicts(LogObject *log_object, int maxConfli // file exists, try to read metafile to get object signature // uint64_t signature = 0; - MetaInfo meta_info(filename); + BaseMetaInfo meta_info(filename); bool conflicts = true; if (meta_info.file_open_successful()) { diff --git a/proxy/logging/Makefile.am b/proxy/logging/Makefile.am index bfcd94209bc..79655a0d6dd 100644 --- a/proxy/logging/Makefile.am +++ b/proxy/logging/Makefile.am @@ -19,6 +19,7 @@ AM_CPPFLAGS = \ $(iocore_include_dirs) \ -I$(top_srcdir)/lib \ + -I$(top_srcdir)/lib/ts \ -I$(top_srcdir)/lib/records \ -I$(top_srcdir)/proxy/api/ts \ -I$(top_srcdir)/proxy \ @@ -27,7 +28,7 @@ AM_CPPFLAGS = \ -I$(top_srcdir)/proxy/hdrs \ -I$(top_srcdir)/proxy/shared \ -I$(top_srcdir)/mgmt \ - -I$(top_srcdir)/mgmt/utils + -I$(top_srcdir)/mgmt/utils EXTRA_DIST = LogStandalone.cc diff --git a/proxy/shared/DiagsConfig.cc b/proxy/shared/DiagsConfig.cc index 8a5f3f28c89..87203a90d22 100644 --- a/proxy/shared/DiagsConfig.cc +++ b/proxy/shared/DiagsConfig.cc @@ -272,7 +272,6 @@ DiagsConfig::DiagsConfig(const char *filename, const char *tags, const char *act ats_scoped_str logpath; callbacks_established = false; - diags_log_fp = (FILE *)NULL; diags = NULL; //////////////////////////////////////////////////////////////////// @@ -299,24 +298,21 @@ DiagsConfig::DiagsConfig(const char *filename, const char *tags, const char *act ink_filepath_make(diags_logpath, sizeof(diags_logpath), logpath, filename); - // open write append - // diags_log_fp = fopen(diags_logpath,"w"); - diags_log_fp = fopen(diags_logpath, "a+"); - if (diags_log_fp) { - int status; - status = setvbuf(diags_log_fp, NULL, _IOLBF, 512); - if (status != 0) { - fclose(diags_log_fp); - diags_log_fp = NULL; - } - } + // Grab rolling intervals from configuration + // TODO error check these values + int output_log_roll_int = (int)REC_ConfigReadInteger("proxy.config.output.logfile.rolling_interval_sec"); + int output_log_roll_size = (int)REC_ConfigReadInteger("proxy.config.output.logfile.rolling_size_mb"); + int output_log_roll_enable = (int)REC_ConfigReadInteger("proxy.config.output.logfile.rolling_enabled"); + int diags_log_roll_int = (int)REC_ConfigReadInteger("proxy.config.diags.logfile.rolling_interval_sec"); + int diags_log_roll_size = (int)REC_ConfigReadInteger("proxy.config.diags.logfile.rolling_size_mb"); + int diags_log_roll_enable = (int)REC_ConfigReadInteger("proxy.config.diags.logfile.rolling_enabled"); + + // Set up diags, FILE streams are opened in Diags constructor + diags_log = new BaseLogFile(diags_logpath); + diags = new Diags(tags, actions, diags_log); + diags->config_roll_diagslog((RollingEnabledValues)diags_log_roll_enable, diags_log_roll_int, diags_log_roll_size); + diags->config_roll_outputlog((RollingEnabledValues)output_log_roll_enable, output_log_roll_int, output_log_roll_size); - diags = new Diags(tags, actions, diags_log_fp); - if (diags_log_fp == NULL) { - diags->print(NULL, DTA(DL_Warning), "couldn't open diags log file '%s', " - "will not log to this file", - diags_logpath); - } diags->print(NULL, DTA(DL_Status), "opened %s", diags_logpath); register_diags_callbacks(); @@ -370,9 +366,5 @@ DiagsConfig::register_diags_callbacks() DiagsConfig::~DiagsConfig() { - if (diags_log_fp) { - fclose(diags_log_fp); - diags_log_fp = NULL; - } delete diags; } diff --git a/proxy/shared/DiagsConfig.h b/proxy/shared/DiagsConfig.h index f6ac82c88d5..68f9ed2ec8f 100644 --- a/proxy/shared/DiagsConfig.h +++ b/proxy/shared/DiagsConfig.h @@ -23,7 +23,8 @@ #ifndef __DIAGSCONFIG_H__ #define __DIAGSCONFIG_H__ -#include "ts/Diags.h" +#include "Diags.h" +#include "BaseLogFile.h" struct DiagsConfig { void reconfigure_diags(); @@ -37,7 +38,7 @@ struct DiagsConfig { private: bool callbacks_established; - FILE *diags_log_fp; + BaseLogFile *diags_log; public: Diags *diags; diff --git a/proxy/shared/Makefile.am b/proxy/shared/Makefile.am index 577f8b340a9..b107ca29859 100644 --- a/proxy/shared/Makefile.am +++ b/proxy/shared/Makefile.am @@ -26,6 +26,8 @@ noinst_LIBRARIES = \ AM_CPPFLAGS = \ $(iocore_include_dirs) \ -I$(top_srcdir)/lib/records \ + -I$(top_srcdir)/lib/ts \ + -I$(top_builddir)/lib/ts \ -I$(top_srcdir)/mgmt \ -I$(top_srcdir)/mgmt/api \ -I$(top_srcdir)/mgmt/api/include \ @@ -36,7 +38,8 @@ AM_CPPFLAGS = \ -I$(top_srcdir)/proxy/http \ -I$(top_srcdir)/proxy/hdrs \ -I$(top_srcdir)/proxy/logging \ - -I$(top_srcdir)/lib + -I$(top_srcdir)/lib \ + -I$(top_builddir)/lib liberror_a_SOURCES = \ Error.cc From e5664d57dbb6239844213d9e8b920ada88e6dbdc Mon Sep 17 00:00:00 2001 From: Daniel Xu Date: Mon, 10 Aug 2015 15:29:35 -0700 Subject: [PATCH 2/6] Fix Makefile indentation --- cmd/traffic_crashlog/Makefile.am | 2 +- cmd/traffic_ctl/Makefile.am | 2 +- cmd/traffic_manager/Makefile.am | 2 +- lib/ts/Makefile.am | 4 ++-- proxy/Makefile.am | 2 +- proxy/shared/Makefile.am | 6 +++--- 6 files changed, 9 insertions(+), 9 deletions(-) diff --git a/cmd/traffic_crashlog/Makefile.am b/cmd/traffic_crashlog/Makefile.am index b0458fecaf0..f1ec65142c3 100644 --- a/cmd/traffic_crashlog/Makefile.am +++ b/cmd/traffic_crashlog/Makefile.am @@ -20,7 +20,7 @@ bin_PROGRAMS = traffic_crashlog AM_CPPFLAGS = \ $(iocore_include_dirs) \ -I$(top_srcdir)/lib \ - -I$(top_srcdir)/lib/ts \ + -I$(top_srcdir)/lib/ts \ -I$(top_srcdir)/lib/records \ -I$(top_srcdir)/mgmt \ -I$(top_srcdir)/mgmt/utils \ diff --git a/cmd/traffic_ctl/Makefile.am b/cmd/traffic_ctl/Makefile.am index e4ff0769c77..d83fd19c24b 100644 --- a/cmd/traffic_ctl/Makefile.am +++ b/cmd/traffic_ctl/Makefile.am @@ -20,7 +20,7 @@ AM_CPPFLAGS = \ $(iocore_include_dirs) \ -I$(top_srcdir)/lib \ - -I$(top_srcdir)/lib/ts \ + -I$(top_srcdir)/lib/ts \ -I$(top_srcdir)/lib/records \ -I$(top_srcdir)/mgmt/api/include diff --git a/cmd/traffic_manager/Makefile.am b/cmd/traffic_manager/Makefile.am index a099f47daf9..273a1e8c877 100644 --- a/cmd/traffic_manager/Makefile.am +++ b/cmd/traffic_manager/Makefile.am @@ -29,7 +29,7 @@ AM_CPPFLAGS = \ -I$(top_srcdir)/mgmt/cluster \ -I$(top_srcdir)/mgmt/utils \ -I$(top_srcdir)/lib \ - -I$(top_srcdir)/lib/ts + -I$(top_srcdir)/lib/ts AM_LDFLAGS = \ @EXTRA_CXX_LDFLAGS@ \ diff --git a/lib/ts/Makefile.am b/lib/ts/Makefile.am index 46ddda5f83b..fe12872be60 100644 --- a/lib/ts/Makefile.am +++ b/lib/ts/Makefile.am @@ -43,8 +43,8 @@ libtsutil_la_SOURCES = \ Allocator.h \ Arena.cc \ Arena.h \ - BaseLogFile.cc \ - BaseLogFile.h \ + BaseLogFile.cc \ + BaseLogFile.h \ Bitops.cc \ Bitops.h \ ConsistentHash.cc \ diff --git a/proxy/Makefile.am b/proxy/Makefile.am index 7e228c86471..ae74049f225 100644 --- a/proxy/Makefile.am +++ b/proxy/Makefile.am @@ -47,7 +47,7 @@ AM_CPPFLAGS = \ -I$(top_srcdir)/mgmt/utils \ -I$(top_srcdir)/proxy/api/ts \ -I$(top_srcdir)/lib \ - -I$(top_srcdir)/lib/ts \ + -I$(top_srcdir)/lib/ts \ @OPENSSL_INCLUDES@ # NOTE: it is safe to use AM_LDFLAGS here because we are only building executables. If we start diff --git a/proxy/shared/Makefile.am b/proxy/shared/Makefile.am index b107ca29859..f454e23d650 100644 --- a/proxy/shared/Makefile.am +++ b/proxy/shared/Makefile.am @@ -26,8 +26,8 @@ noinst_LIBRARIES = \ AM_CPPFLAGS = \ $(iocore_include_dirs) \ -I$(top_srcdir)/lib/records \ - -I$(top_srcdir)/lib/ts \ - -I$(top_builddir)/lib/ts \ + -I$(top_srcdir)/lib/ts \ + -I$(top_builddir)/lib/ts \ -I$(top_srcdir)/mgmt \ -I$(top_srcdir)/mgmt/api \ -I$(top_srcdir)/mgmt/api/include \ @@ -39,7 +39,7 @@ AM_CPPFLAGS = \ -I$(top_srcdir)/proxy/hdrs \ -I$(top_srcdir)/proxy/logging \ -I$(top_srcdir)/lib \ - -I$(top_builddir)/lib + -I$(top_builddir)/lib liberror_a_SOURCES = \ Error.cc From 0a423a94aa9fc7b4eb83e83b2498c16122e9b6de Mon Sep 17 00:00:00 2001 From: Daniel Xu Date: Mon, 10 Aug 2015 15:31:09 -0700 Subject: [PATCH 3/6] Fix 'make check' seg fault Crash would happen if ElevateAccess constructor called Fatal(..), since Diags wasn't property initialized yet --- lib/ts/BaseLogFile.cc | 7 ------- 1 file changed, 7 deletions(-) diff --git a/lib/ts/BaseLogFile.cc b/lib/ts/BaseLogFile.cc index a15152d7184..586992c594c 100644 --- a/lib/ts/BaseLogFile.cc +++ b/lib/ts/BaseLogFile.cc @@ -292,9 +292,6 @@ BaseLogFile::open_file(int perm) return LOG_FILE_NO_ERROR; } - // get root; destructor will release access - // ElevateAccess accesss(true); - // means this object is representing a real file on disk m_is_regfile = true; @@ -518,10 +515,6 @@ BaseMetaInfo::_read_from_file() void BaseMetaInfo::_write_to_file() { - // get root - // ElevateAccess follows RAII design, the destructor will release root - ElevateAccess accesss(true); - int fd = open(_filename, O_WRONLY | O_CREAT | O_TRUNC, LOGFILE_DEFAULT_PERMS); if (fd < 0) { log_log_error("Could not open metafile %s for writing: %s\n", _filename, strerror(errno)); From e7e2f6c76f776927aac8b43966e78e7732d57c8d Mon Sep 17 00:00:00 2001 From: Daniel Xu Date: Tue, 11 Aug 2015 10:15:28 -0700 Subject: [PATCH 4/6] Add documentation for rolling traffic.out and Diags class --- .../configuration/records.config.en.rst | 44 +++++++++++++++++++ mgmt/RecordsConfig.cc | 2 +- 2 files changed, 45 insertions(+), 1 deletion(-) diff --git a/doc/reference/configuration/records.config.en.rst b/doc/reference/configuration/records.config.en.rst index 257e070fbf7..8bee69435f6 100644 --- a/doc/reference/configuration/records.config.en.rst +++ b/doc/reference/configuration/records.config.en.rst @@ -214,6 +214,28 @@ A value of ``0`` means no signal will be sent. The name and location of the file that contains warnings, status messages, and error messages produced by the Traffic Server processes. If no path is specified, then Traffic Server creates the file in its logging directory. +.. ts:cv:: CONFIG proxy.config.output.logfile.rolling_enabled INT 0 + :reloadable: + + Specifies how the output log is rolled. You can specify the following values: + + - ``0`` = disables output log rolling + - ``1`` = enables output log rolling at specific intervals (specified with the + `proxy.config.output.logfile.rolling_interval_sec`_ variable). The "clock" starts ticking on Traffic Server boot + - ``2`` = enables output log rolling when the output log reaches a specific size (specified with the `proxy.config.output.logfile.rolling_size_mb`_ variable) + +.. ts:cv:: CONFIG proxy.config.output.logfile.rolling_interval_sec INT 3600 + :reloadable: + :metric: seconds + + Specifies how often the output log is rolled, in seconds. The timer starts on Traffic Server bootup. + +.. ts:cv:: CONFIG proxy.config.output.logfile.rolling_size_mb INT 100 + :reloadable: + :metric: megabytes + + Specifies at what size to roll the output log at. + .. ts:cv:: CONFIG proxy.config.snapshot_dir STRING snapshots The directory in which Traffic Server stores configuration @@ -2227,6 +2249,28 @@ ssl TLS termination and certificate processing the :c:func:`TSDebug` API, passing the plugin name as the debug tag. +.. ts:cv:: CONFIG proxy.config.diags.logfile.rolling_enabled INT 0 + :reloadable: + + Specifies how the diagnostics log is rolled. You can specify the following values: + + - ``0`` = disables diagnostics log rolling + - ``1`` = enables diagnostics log rolling at specific intervals (specified with the + `proxy.config.diags.logfile.rolling_interval_sec`_ variable). The "clock" starts ticking on Traffic Server boot + - ``2`` = enables diagnostics log rolling when the diagnostics log reaches a specific size (specified with the `proxy.config.diags.logfile.rolling_size_mb`_ variable) + +.. ts:cv:: CONFIG proxy.config.diags.logfile.rolling_interval_sec INT 3600 + :reloadable: + :metric: seconds + + Specifies how often the diagnostics log is rolled, in seconds. The timer starts on Traffic Server bootup. + +.. ts:cv:: CONFIG proxy.config.diags.logfile.rolling_size_mb INT 100 + :reloadable: + :metric: megabytes + + Specifies at what size to roll the diagnostics log at. + Reverse Proxy ============= diff --git a/mgmt/RecordsConfig.cc b/mgmt/RecordsConfig.cc index 2c8cfa69e66..57991870520 100644 --- a/mgmt/RecordsConfig.cc +++ b/mgmt/RecordsConfig.cc @@ -102,7 +102,7 @@ static const RecordElement RecordsConfig[] = , {RECT_CONFIG, "proxy.config.output.logfile.rolling_interval_sec", RECD_INT, "3600", RECU_DYNAMIC, RR_NULL, RECC_STR, "^[0-9]+$", RECA_NULL} , - {RECT_CONFIG, "proxy.config.output.logfile.rolling_size_mb", RECD_INT, "10", RECU_DYNAMIC, RR_NULL, RECC_STR, "^0*[1-9][0-9]*$", RECA_NULL} + {RECT_CONFIG, "proxy.config.output.logfile.rolling_size_mb", RECD_INT, "100", RECU_DYNAMIC, RR_NULL, RECC_STR, "^0*[1-9][0-9]*$", RECA_NULL} , {RECT_CONFIG, "proxy.config.snapshot_dir", RECD_STRING, "snapshots", RECU_NULL, RR_REQUIRED, RECC_NULL, NULL, RECA_NULL} , From e56122a473361e39fda9e4adeca3e09ef0c03a9d Mon Sep 17 00:00:00 2001 From: Daniel Xu Date: Tue, 11 Aug 2015 16:09:21 -0700 Subject: [PATCH 5/6] Fix issues found in code review Things done: - Code style changes - Removed extraneous include directories in `Makefile.am`s, as noted in TS-3759 - Removed superfluous NULL checks that didn't do much - Created a unified `init()` method for BaseLogFile, so that code isn't repeated in the various constructors - Fixed typo where `m_hostname` wasn't being `strdup()`ed properly within BaseLogFile copy constructor - Used `ats_scoped_str` instead of `char *` for `m_hostname` and `m_name` in BaseLogFile, so that memory management is more elegant - Removed unnecessary function call to `strcmp()`. It now checks if the first char in the string is NUL. Done to improve performance. - Removed use of hard coded constants and replaced with `sizeof(..)` - Use prefix ++ operator instead of postfix ++ - Put back in `LogFile::rolled_logfile()` and `LogFile::exists()` so that clients of LogFile need not be aware of underlying BaseLogFile implementation. These functions just redirect the input into the relevant BaseLogFile functions now. - Ran clang-format --- cmd/traffic_cop/traffic_cop.cc | 4 +- cmd/traffic_crashlog/Makefile.am | 1 - cmd/traffic_crashlog/traffic_crashlog.cc | 5 +- cmd/traffic_ctl/Makefile.am | 1 - cmd/traffic_ctl/traffic_ctl.h | 6 +- cmd/traffic_manager/Makefile.am | 3 +- cmd/traffic_manager/traffic_manager.cc | 4 +- iocore/eventsystem/test_Event.cc | 2 +- lib/ts/BaseLogFile.cc | 117 ++++++++++++----------- lib/ts/BaseLogFile.h | 11 +-- lib/ts/Diags.h | 1 - proxy/Main.cc | 4 +- proxy/Makefile.am | 3 +- proxy/logging/LogConfig.cc | 2 +- proxy/logging/LogFile.cc | 22 ++++- proxy/logging/LogFile.h | 2 + proxy/logging/Makefile.am | 3 +- proxy/shared/DiagsConfig.h | 4 +- proxy/shared/Makefile.am | 5 +- 19 files changed, 105 insertions(+), 95 deletions(-) diff --git a/cmd/traffic_cop/traffic_cop.cc b/cmd/traffic_cop/traffic_cop.cc index f1eab7eaeea..d1e6da6ea35 100644 --- a/cmd/traffic_cop/traffic_cop.cc +++ b/cmd/traffic_cop/traffic_cop.cc @@ -94,8 +94,8 @@ static gid_t admin_gid; static bool admin_user_p = false; static char manager_binary[PATH_NAME_MAX] = "traffic_manager"; static char server_binary[PATH_NAME_MAX] = "traffic_server"; -static char manager_options[OPTIONS_LEN_MAX] = ""; - +static char manager_options[OPTIONS_LEN_MAX] = ""; + static char log_file[PATH_NAME_MAX] = "traffic.out"; diff --git a/cmd/traffic_crashlog/Makefile.am b/cmd/traffic_crashlog/Makefile.am index f1ec65142c3..b977f51e5cf 100644 --- a/cmd/traffic_crashlog/Makefile.am +++ b/cmd/traffic_crashlog/Makefile.am @@ -20,7 +20,6 @@ bin_PROGRAMS = traffic_crashlog AM_CPPFLAGS = \ $(iocore_include_dirs) \ -I$(top_srcdir)/lib \ - -I$(top_srcdir)/lib/ts \ -I$(top_srcdir)/lib/records \ -I$(top_srcdir)/mgmt \ -I$(top_srcdir)/mgmt/utils \ diff --git a/cmd/traffic_crashlog/traffic_crashlog.cc b/cmd/traffic_crashlog/traffic_crashlog.cc index d910e0e1df8..a965d827a03 100644 --- a/cmd/traffic_crashlog/traffic_crashlog.cc +++ b/cmd/traffic_crashlog/traffic_crashlog.cc @@ -29,7 +29,7 @@ #include "ts/ink_syslog.h" #include "I_RecProcess.h" #include "RecordsConfig.h" -#include "BaseLogFile.h" +#include "ts/BaseLogFile.h" static int syslog_mode = false; static int debug_mode = false; @@ -92,8 +92,7 @@ main(int /* argc ATS_UNUSED */, const char **argv) crashlog_target target; pid_t parent = getppid(); - BaseLogFile *base_log_file = new BaseLogFile("stderr"); - diags = new Diags("" /* tags */, "" /* actions */, base_log_file); + diags = new Diags("" /* tags */, "" /* actions */, new BaseLogFile("stderr")); appVersionInfo.setup(PACKAGE_NAME, "traffic_crashlog", PACKAGE_VERSION, __DATE__, __TIME__, BUILD_MACHINE, BUILD_PERSON, ""); diff --git a/cmd/traffic_ctl/Makefile.am b/cmd/traffic_ctl/Makefile.am index d83fd19c24b..5b7731bc764 100644 --- a/cmd/traffic_ctl/Makefile.am +++ b/cmd/traffic_ctl/Makefile.am @@ -20,7 +20,6 @@ AM_CPPFLAGS = \ $(iocore_include_dirs) \ -I$(top_srcdir)/lib \ - -I$(top_srcdir)/lib/ts \ -I$(top_srcdir)/lib/records \ -I$(top_srcdir)/mgmt/api/include diff --git a/cmd/traffic_ctl/traffic_ctl.h b/cmd/traffic_ctl/traffic_ctl.h index 49e9987bb47..27927862261 100644 --- a/cmd/traffic_ctl/traffic_ctl.h +++ b/cmd/traffic_ctl/traffic_ctl.h @@ -28,9 +28,9 @@ #include "ts/Diags.h" #include "ts/ink_memory.h" #include "mgmtapi.h" -#include "ink_args.h" -#include "I_Version.h" -#include "BaseLogFile.h" +#include "ts/ink_args.h" +#include "ts/I_Version.h" +#include "ts/BaseLogFile.h" #include #include diff --git a/cmd/traffic_manager/Makefile.am b/cmd/traffic_manager/Makefile.am index 273a1e8c877..fecdd493e74 100644 --- a/cmd/traffic_manager/Makefile.am +++ b/cmd/traffic_manager/Makefile.am @@ -28,8 +28,7 @@ AM_CPPFLAGS = \ -I$(top_srcdir)/mgmt/api/include \ -I$(top_srcdir)/mgmt/cluster \ -I$(top_srcdir)/mgmt/utils \ - -I$(top_srcdir)/lib \ - -I$(top_srcdir)/lib/ts + -I$(top_srcdir)/lib AM_LDFLAGS = \ @EXTRA_CXX_LDFLAGS@ \ diff --git a/cmd/traffic_manager/traffic_manager.cc b/cmd/traffic_manager/traffic_manager.cc index fd734578b11..1db3141f41d 100644 --- a/cmd/traffic_manager/traffic_manager.cc +++ b/cmd/traffic_manager/traffic_manager.cc @@ -615,7 +615,7 @@ main(int argc, const char **argv) // we must pass in bind_stdout and bind_stderr values to TS // we do it so TS is able to create BaseLogFiles for each value - if (strcmp(bind_stdout, "") != 0) { + if (*bind_stdout != 0) { lmgmt->proxy_options = (char *)ats_realloc(lmgmt->proxy_options, strlen(lmgmt->proxy_options) + 1 /* space */ + strlen("--bind_stdout ") + strlen(bind_stdout) + 1 /* null term */); @@ -623,7 +623,7 @@ main(int argc, const char **argv) strcat(lmgmt->proxy_options, bind_stdout); } - if (strcmp(bind_stderr, "") != 0) { + if (*bind_stderr != 0) { lmgmt->proxy_options = (char *)ats_realloc(lmgmt->proxy_options, strlen(lmgmt->proxy_options) + 1 /* space */ + strlen("--bind_stderr ") + strlen(bind_stderr) + 1 /* null term */); diff --git a/iocore/eventsystem/test_Event.cc b/iocore/eventsystem/test_Event.cc index b480db7c8c5..c7d58ac6a1e 100644 --- a/iocore/eventsystem/test_Event.cc +++ b/iocore/eventsystem/test_Event.cc @@ -97,7 +97,7 @@ init_diags(const char *bdt, const char *bat) BaseLogFile *blf = new BaseLogFile(diags_logpath); diags = new Diags(bdt, bat, blf); - if (blf && blf->m_fp == NULL) { + if (blf->m_fp == NULL) { Warning("couldn't open diags log file '%s', " "will not log to this file", diags_logpath); diff --git a/lib/ts/BaseLogFile.cc b/lib/ts/BaseLogFile.cc index 586992c594c..ea1477a0dae 100644 --- a/lib/ts/BaseLogFile.cc +++ b/lib/ts/BaseLogFile.cc @@ -27,43 +27,32 @@ * This consturctor creates a BaseLogFile based on a given name. * This is the most common way BaseLogFiles are created. */ -BaseLogFile::BaseLogFile(const char *name) - : m_name(ats_strdup(name)), m_hostname(NULL), m_is_regfile(false), m_has_signature(false), m_signature(0), m_is_init(false) +BaseLogFile::BaseLogFile(const char *name) : m_signature(0), m_has_signature(false) { - m_fp = NULL; - m_start_time = time(0); - m_end_time = 0L; - m_bytes_written = 0; - m_meta_info = NULL; - - log_log_trace("exiting BaseLogFile constructor, m_name=%s, this=%p\n", m_name, this); + init(name); + log_log_trace("exiting BaseLogFile constructor, m_name=%s, this=%p\n", (char *)m_name, this); } /* * This consturctor creates a BaseLogFile based on a given name. * Similar to above constructor, but is overloaded with the object signature */ -BaseLogFile::BaseLogFile(const char *name, uint64_t sig) - : m_name(ats_strdup(name)), m_hostname(NULL), m_is_regfile(false), m_has_signature(true), m_signature(sig), m_is_init(false) +BaseLogFile::BaseLogFile(const char *name, uint64_t sig) : m_signature(sig), m_has_signature(true) { - m_fp = NULL; - m_start_time = time(0); - m_end_time = 0L; - m_bytes_written = 0; - m_meta_info = NULL; - - log_log_trace("exiting BaseLogFile constructor, m_name=%s, this=%p\n", m_name, this); + init(name); + log_log_trace("exiting BaseLogFile signature constructor, m_name=%s, m_signature=%ld, this=%p\n", (char *)m_name, m_signature, + this); } /* * This copy constructor creates a BaseLogFile based on a given copy. */ BaseLogFile::BaseLogFile(const BaseLogFile ©) - : m_fp(NULL), m_start_time(copy.m_start_time), m_end_time(0L), m_bytes_written(0), m_name(ats_strdup(copy.m_name)), - m_hostname(ats_strdup(m_hostname)), m_is_regfile(false), m_has_signature(copy.m_has_signature), m_signature(copy.m_signature), - m_is_init(copy.m_is_init), m_meta_info(NULL) + : m_fp(NULL), m_start_time(copy.m_start_time), m_end_time(0L), m_bytes_written(0), m_signature(copy.m_signature), + m_has_signature(copy.m_has_signature), m_name(ats_strdup(copy.m_name)), m_hostname(ats_strdup(copy.m_hostname)), + m_is_regfile(false), m_is_init(copy.m_is_init), m_meta_info(NULL) { - log_log_trace("exiting BaseLogFile copy constructor, m_name=%s, this=%p\n", m_name, this); + log_log_trace("exiting BaseLogFile copy constructor, m_name=%s, this=%p\n", (char *)m_name, this); } /* @@ -71,20 +60,33 @@ BaseLogFile::BaseLogFile(const BaseLogFile ©) */ BaseLogFile::~BaseLogFile() { - log_log_trace("entering BaseLogFile destructor, m_name=%s, this=%p\n", m_name, this); + log_log_trace("entering BaseLogFile destructor, m_name=%s, this=%p\n", (char *)m_name, this); if (m_is_regfile) close_file(); else - log_log_trace("not a regular file, not closing, m_name=%s, this=%p\n", m_name, this); - if (m_name) - ats_free(m_name); - if (m_hostname) - ats_free(m_hostname); + log_log_trace("not a regular file, not closing, m_name=%s, this=%p\n", (char *)m_name, this); log_log_trace("exiting BaseLogFile destructor, this=%p\n", this); } +/* + * Initializes the defaults of some of the common member values of this class + */ +void +BaseLogFile::init(const char *name) +{ + m_fp = NULL; + m_start_time = time(0); + m_end_time = 0L; + m_bytes_written = 0; + m_name = ats_strdup(name); + m_hostname = NULL; + m_is_regfile = false; + m_is_init = false; + m_meta_info = NULL; +} + /* * This function is called by a client of BaseLogFile to roll the underlying * file The tricky part to this routine is in coming up with the new file name, @@ -112,20 +114,20 @@ int BaseLogFile::roll(long interval_start, long interval_end) { // First, let's see if a roll is even needed. - if (m_name == NULL || !BaseLogFile::exists(m_name)) { - log_log_trace("Roll not needed for %s; file doesn't exist\n", (m_name) ? m_name : "no_name\n"); + if (m_name == NULL || !BaseLogFile::exists((char *)m_name)) { + log_log_trace("Roll not needed for %s; file doesn't exist\n", ((char *)m_name) ? (char *)m_name : "no_name\n"); return 0; } // Then, check if this object is backing a regular file if (!m_is_regfile) { - log_log_trace("Roll not needed for %s; not regular file\n", (m_name) ? m_name : "no_name\n"); + log_log_trace("Roll not needed for %s; not regular file\n", ((char *)m_name) ? (char *)m_name : "no_name\n"); return 0; } // Read meta info if needed (if file was not opened) if (!m_meta_info) { - m_meta_info = new BaseMetaInfo(m_name); + m_meta_info = new BaseMetaInfo((char *)m_name); } // Create the new file name, which consists of a timestamp and rolled @@ -179,10 +181,11 @@ BaseLogFile::roll(long interval_start, long interval_end) // Now that we have our timestamp values, convert them to the proper // timestamp formats and create the rolled file name. - timestamp_to_str((long)start, start_time_ext, 64); - timestamp_to_str((long)end, end_time_ext, 64); - snprintf(roll_name, LOGFILE_ROLL_MAXPATHLEN, "%s%s%s.%s-%s%s", m_name, (m_hostname ? LOGFILE_SEPARATOR_STRING : ""), - (m_hostname ? m_hostname : ""), start_time_ext, end_time_ext, LOGFILE_ROLLED_EXTENSION); + timestamp_to_str((long)start, start_time_ext, sizeof(start_time_ext)); + timestamp_to_str((long)end, end_time_ext, sizeof(start_time_ext)); + snprintf(roll_name, LOGFILE_ROLL_MAXPATHLEN, "%s%s%s.%s-%s%s", (char *)m_name, + ((char *)m_hostname ? LOGFILE_SEPARATOR_STRING : ""), ((char *)m_hostname ? (char *)m_hostname : ""), start_time_ext, + end_time_ext, LOGFILE_ROLLED_EXTENSION); // It may be possible that the file we want to roll into already // exists. If so, then we need to add a version tag to the rolled @@ -192,16 +195,17 @@ BaseLogFile::roll(long interval_start, long interval_end) log_log_trace("The rolled file %s already exists; adding version " "tag %d to avoid clobbering the existing file.\n", roll_name, version); - snprintf(roll_name, LOGFILE_ROLL_MAXPATHLEN, "%s%s%s.%s-%s.%d%s", m_name, (m_hostname ? LOGFILE_SEPARATOR_STRING : ""), - (m_hostname ? m_hostname : ""), start_time_ext, end_time_ext, version, LOGFILE_ROLLED_EXTENSION); - version++; + snprintf(roll_name, LOGFILE_ROLL_MAXPATHLEN, "%s%s%s.%s-%s.%d%s", (char *)m_name, + ((char *)m_hostname ? LOGFILE_SEPARATOR_STRING : ""), ((char *)m_hostname ? (char *)m_hostname : ""), start_time_ext, + end_time_ext, version, LOGFILE_ROLLED_EXTENSION); + ++version; } // It's now safe to rename the file. - if (::rename(m_name, roll_name) < 0) { + if (::rename((char *)m_name, roll_name) < 0) { log_log_error("Traffic Server could not rename logfile %s to %s, error %d: " "%s.\n", - m_name, roll_name, errno, strerror(errno)); + (char *)m_name, roll_name, errno, strerror(errno)); return 0; } @@ -209,7 +213,7 @@ BaseLogFile::roll(long interval_start, long interval_end) m_start_time = 0; m_bytes_written = 0; - log_log_trace("The logfile %s was rolled to %s.\n", m_name, roll_name); + log_log_trace("The logfile %s was rolled to %s.\n", (char *)m_name, roll_name); return 1; } @@ -280,12 +284,15 @@ BaseLogFile::open_file(int perm) return LOG_FILE_NO_ERROR; } - if (m_name && !strcmp(m_name, "stdout")) { + if (!(char *)m_name) { + log_log_error("BaseLogFile: m_name is NULL, aborting open_file()\n"); + return LOG_FILE_COULD_NOT_OPEN_FILE; + } else if (!strcmp((char *)m_name, "stdout")) { log_log_trace("BaseLogFile: stdout opened\n"); m_fp = stdout; m_is_init = true; return LOG_FILE_NO_ERROR; - } else if (m_name && !strcmp(m_name, "stderr")) { + } else if (!strcmp((char *)m_name, "stderr")) { log_log_trace("BaseLogFile: stderr opened\n"); m_fp = stderr; m_is_init = true; @@ -297,31 +304,31 @@ BaseLogFile::open_file(int perm) // Check to see if the file exists BEFORE we try to open it, since // opening it will also create it. - bool file_exists = BaseLogFile::exists(m_name); + bool file_exists = BaseLogFile::exists((char *)m_name); if (file_exists) { if (!m_meta_info) { // This object must be fresh since it has not built its MetaInfo // so we create a new MetaInfo object that will read right away // (in the constructor) the corresponding metafile - m_meta_info = new BaseMetaInfo(m_name); + m_meta_info = new BaseMetaInfo((char *)m_name); } } else { // The log file does not exist, so we create a new MetaInfo object // which will save itself to disk right away (in the constructor) if (m_has_signature) - m_meta_info = new BaseMetaInfo(m_name, (long)time(0), m_signature); + m_meta_info = new BaseMetaInfo((char *)m_name, (long)time(0), m_signature); else - m_meta_info = new BaseMetaInfo(m_name, (long)time(0)); + m_meta_info = new BaseMetaInfo((char *)m_name, (long)time(0)); } // open actual log file (not metainfo) - log_log_trace("BaseLogFile: attempting to open %s\n", m_name); - m_fp = fopen(m_name, "a+"); + log_log_trace("BaseLogFile: attempting to open %s\n", (char *)m_name); + m_fp = fopen((char *)m_name, "a+"); // error check if (!m_fp) { - log_log_error("Error opening log file %s: %s\n", m_name, strerror(errno)); + log_log_error("Error opening log file %s: %s\n", (char *)m_name, strerror(errno)); log_log_error("Actual error: %s\n", (errno == EINVAL ? "einval" : "something else")); return LOG_FILE_COULD_NOT_OPEN_FILE; } @@ -329,14 +336,14 @@ BaseLogFile::open_file(int perm) // set permissions if necessary if (perm != -1) { // means LogFile passed in some permissions we need to set - if (chmod(m_name, perm) != 0) - log_log_error("Error changing logfile=%s permissions: %s\n", m_name, strerror(errno)); + if (chmod((char *)m_name, perm) != 0) + log_log_error("Error changing logfile=%s permissions: %s\n", (char *)m_name, strerror(errno)); } // set m_bytes_written to force the rolling based on filesize. m_bytes_written = fseek(m_fp, 0, SEEK_CUR); - log_log_trace("BaseLogFile %s is now open (fd=%d)\n", m_name, fileno(m_fp)); + log_log_trace("BaseLogFile %s is now open (fd=%d)\n", (char *)m_name, fileno(m_fp)); m_is_init = true; return LOG_FILE_NO_ERROR; } @@ -349,7 +356,7 @@ BaseLogFile::close_file() { if (is_open()) { fclose(m_fp); - log_log_trace("BaseLogFile %s is closed\n", m_name); + log_log_trace("BaseLogFile %s is closed\n", (char *)m_name); m_fp = NULL; m_is_init = false; } diff --git a/lib/ts/BaseLogFile.h b/lib/ts/BaseLogFile.h index e2938fe994a..c7ba90bfce6 100644 --- a/lib/ts/BaseLogFile.h +++ b/lib/ts/BaseLogFile.h @@ -208,8 +208,6 @@ class BaseLogFile void set_hostname(const char *hn) { - if (m_hostname) - ats_free(m_hostname); m_hostname = ats_strdup(hn); } @@ -227,6 +225,7 @@ class BaseLogFile volatile uint64_t m_bytes_written; private: + void init(const char *name); // member functions not allowed BaseLogFile(); BaseLogFile &operator=(const BaseLogFile &); @@ -235,11 +234,11 @@ class BaseLogFile int timestamp_to_str(long timestamp, char *buf, int size); // member variables - char *m_name; - char *m_hostname; - bool m_is_regfile; - bool m_has_signature; uint64_t m_signature; + bool m_has_signature; + ats_scoped_str m_name; + ats_scoped_str m_hostname; + bool m_is_regfile; bool m_is_init; BaseMetaInfo *m_meta_info; }; diff --git a/lib/ts/Diags.h b/lib/ts/Diags.h index cebad82a0d6..8038ce7daa5 100644 --- a/lib/ts/Diags.h +++ b/lib/ts/Diags.h @@ -274,7 +274,6 @@ class Diags time_t outputlog_time_last_roll; time_t diagslog_time_last_roll; - void setup_diagslog(BaseLogFile *blf); bool rebind_stdout(int new_fd); bool rebind_stderr(int new_fd); diff --git a/proxy/Main.cc b/proxy/Main.cc index 16465a75490..432196ddd22 100644 --- a/proxy/Main.cc +++ b/proxy/Main.cc @@ -1427,7 +1427,7 @@ bind_outputs(const char *_bind_stdout, const char *_bind_stderr) { ElevateAccess a(true); int log_fd; - if (strcmp(_bind_stdout, "") != 0) { + if (*_bind_stdout != 0) { Debug("log", "binding stdout to %s", _bind_stdout); log_fd = open(_bind_stdout, O_WRONLY | O_APPEND | O_CREAT, 0644); if (log_fd < 0) { @@ -1438,7 +1438,7 @@ bind_outputs(const char *_bind_stdout, const char *_bind_stderr) close(log_fd); } } - if (strcmp(_bind_stderr, "") != 0) { + if (*_bind_stderr != 0) { Debug("log", "binding stderr to %s", _bind_stderr); log_fd = open(_bind_stderr, O_WRONLY | O_APPEND | O_CREAT, 0644); if (log_fd < 0) { diff --git a/proxy/Makefile.am b/proxy/Makefile.am index ae74049f225..1b2023b18af 100644 --- a/proxy/Makefile.am +++ b/proxy/Makefile.am @@ -46,8 +46,7 @@ AM_CPPFLAGS = \ -I$(top_srcdir)/mgmt \ -I$(top_srcdir)/mgmt/utils \ -I$(top_srcdir)/proxy/api/ts \ - -I$(top_srcdir)/lib \ - -I$(top_srcdir)/lib/ts \ + -I$(top_srcdir)/lib @OPENSSL_INCLUDES@ # NOTE: it is safe to use AM_LDFLAGS here because we are only building executables. If we start diff --git a/proxy/logging/LogConfig.cc b/proxy/logging/LogConfig.cc index 402a4f35176..7f04f86a957 100644 --- a/proxy/logging/LogConfig.cc +++ b/proxy/logging/LogConfig.cc @@ -764,7 +764,7 @@ LogConfig::update_space_used() if (sret != -1 && S_ISREG(sbuf.st_mode)) { total_space_used += (int64_t)sbuf.st_size; - if (auto_delete_rolled_files && BaseLogFile::rolled_logfile(m_dir_entry->d_name) && candidate_count < MAX_CANDIDATES) { + if (auto_delete_rolled_files && LogFile::rolled_logfile(m_dir_entry->d_name) && candidate_count < MAX_CANDIDATES) { // // then add this entry to the candidate list // diff --git a/proxy/logging/LogFile.cc b/proxy/logging/LogFile.cc index feb4b578d76..954d570ee26 100644 --- a/proxy/logging/LogFile.cc +++ b/proxy/logging/LogFile.cc @@ -42,7 +42,7 @@ #include "I_Machine.h" #include "LogSock.h" -#include "BaseLogFile.h" +#include "ts/BaseLogFile.h" #include "LogField.h" #include "LogFilter.h" #include "LogFormat.h" @@ -150,7 +150,7 @@ LogFile::open_file() return LOG_FILE_NO_ERROR; } - bool file_exists = BaseLogFile::exists(m_name); + bool file_exists = LogFile::exists(m_name); if (m_file_format == LOG_FILE_PIPE) { // setup pipe @@ -492,6 +492,18 @@ LogFile::write_ascii_logbuffer3(LogBufferHeader *buffer_header, const char *alt_ return total_bytes; } +bool +LogFile::rolled_logfile(char *file) +{ + return BaseLogFile::rolled_logfile(file); +} + +bool +LogFile::exists(const char *pathname) +{ + return BaseLogFile::exists(pathname); +} + /*------------------------------------------------------------------------- LogFile::writeln @@ -558,7 +570,7 @@ LogFile::check_fd() // attept to re-open it, which will create the file if it's not // there. // - if (m_name && !BaseLogFile::exists(m_name)) { + if (m_name && !LogFile::exists(m_name)) { close_file(); } stat_check_count = 0; @@ -589,9 +601,9 @@ bool LogFile::is_open() { if (m_file_format == LOG_FILE_PIPE) - return (m_fd >= 0); + return m_fd >= 0; else - return (m_log && m_log->is_open()); + return m_log && m_log->is_open(); } /* diff --git a/proxy/logging/LogFile.h b/proxy/logging/LogFile.h index f935bb110e1..d102b74c4eb 100644 --- a/proxy/logging/LogFile.h +++ b/proxy/logging/LogFile.h @@ -85,6 +85,8 @@ class LogFile : public LogBufferSink, public RefCountObj static int write_ascii_logbuffer(LogBufferHeader *buffer_header, int fd, const char *path, const char *alt_format = NULL); int write_ascii_logbuffer3(LogBufferHeader *buffer_header, const char *alt_format = NULL); + static bool rolled_logfile(char *file); + static bool exists(const char *pathname); void display(FILE *fd = stdout); int open_file(); diff --git a/proxy/logging/Makefile.am b/proxy/logging/Makefile.am index 79655a0d6dd..bfcd94209bc 100644 --- a/proxy/logging/Makefile.am +++ b/proxy/logging/Makefile.am @@ -19,7 +19,6 @@ AM_CPPFLAGS = \ $(iocore_include_dirs) \ -I$(top_srcdir)/lib \ - -I$(top_srcdir)/lib/ts \ -I$(top_srcdir)/lib/records \ -I$(top_srcdir)/proxy/api/ts \ -I$(top_srcdir)/proxy \ @@ -28,7 +27,7 @@ AM_CPPFLAGS = \ -I$(top_srcdir)/proxy/hdrs \ -I$(top_srcdir)/proxy/shared \ -I$(top_srcdir)/mgmt \ - -I$(top_srcdir)/mgmt/utils + -I$(top_srcdir)/mgmt/utils EXTRA_DIST = LogStandalone.cc diff --git a/proxy/shared/DiagsConfig.h b/proxy/shared/DiagsConfig.h index 68f9ed2ec8f..2ac0f0fc7aa 100644 --- a/proxy/shared/DiagsConfig.h +++ b/proxy/shared/DiagsConfig.h @@ -23,8 +23,8 @@ #ifndef __DIAGSCONFIG_H__ #define __DIAGSCONFIG_H__ -#include "Diags.h" -#include "BaseLogFile.h" +#include "ts/Diags.h" +#include "ts/BaseLogFile.h" struct DiagsConfig { void reconfigure_diags(); diff --git a/proxy/shared/Makefile.am b/proxy/shared/Makefile.am index f454e23d650..577f8b340a9 100644 --- a/proxy/shared/Makefile.am +++ b/proxy/shared/Makefile.am @@ -26,8 +26,6 @@ noinst_LIBRARIES = \ AM_CPPFLAGS = \ $(iocore_include_dirs) \ -I$(top_srcdir)/lib/records \ - -I$(top_srcdir)/lib/ts \ - -I$(top_builddir)/lib/ts \ -I$(top_srcdir)/mgmt \ -I$(top_srcdir)/mgmt/api \ -I$(top_srcdir)/mgmt/api/include \ @@ -38,8 +36,7 @@ AM_CPPFLAGS = \ -I$(top_srcdir)/proxy/http \ -I$(top_srcdir)/proxy/hdrs \ -I$(top_srcdir)/proxy/logging \ - -I$(top_srcdir)/lib \ - -I$(top_builddir)/lib + -I$(top_srcdir)/lib liberror_a_SOURCES = \ Error.cc From 3af7d5ccc2b7588b89836f5f889ad3bf428be915 Mon Sep 17 00:00:00 2001 From: Daniel Xu Date: Thu, 13 Aug 2015 10:29:16 -0700 Subject: [PATCH 6/6] Fix more issues found in code review Things done: - Removed extraneous whitespace - Removed extraneous `#include`s - Fixed accidental removal of `@OPENSSL_INCLUDES` in proxy/Makefile.am - Improved comments - Fixed configuration variable links in documentation - Added in correct BaseLogFile `NULL` checks for iocore/evensystem tests. Previous checks didn't do anything. - Replaced `(char *)` casts with `get()` calls for `ats_scoped_str`s in BaseLogFile. This is more correct than doing a raw cast. - Improved debug statements in BaseLogFile and proxy/Main.cc to be more descriptive - Removed callback forward declares in proxy/Main.cc left over from experimental API. There are no longer used. - Fixed bug where calling `change_name()` in LogFile would not change name in BaseLogFile - Fixed memory leak in `LogFile::close_file()`. was setting `m_log` to `NULL` without deleting first --- cmd/traffic_cop/traffic_cop.cc | 1 - cmd/traffic_manager/traffic_manager.cc | 3 +- .../configuration/records.config.en.rst | 8 +-- iocore/eventsystem/test_Buffer.cc | 2 +- iocore/eventsystem/test_Event.cc | 2 +- lib/ts/BaseLogFile.cc | 64 +++++++++---------- lib/ts/BaseLogFile.h | 1 + lib/ts/Diags.h | 1 - proxy/Main.cc | 6 +- proxy/Makefile.am | 2 +- proxy/logging/LogFile.cc | 3 + 11 files changed, 44 insertions(+), 49 deletions(-) diff --git a/cmd/traffic_cop/traffic_cop.cc b/cmd/traffic_cop/traffic_cop.cc index d1e6da6ea35..054365deab0 100644 --- a/cmd/traffic_cop/traffic_cop.cc +++ b/cmd/traffic_cop/traffic_cop.cc @@ -96,7 +96,6 @@ static char manager_binary[PATH_NAME_MAX] = "traffic_manager"; static char server_binary[PATH_NAME_MAX] = "traffic_server"; static char manager_options[OPTIONS_LEN_MAX] = ""; - static char log_file[PATH_NAME_MAX] = "traffic.out"; static int synthetic_port = 8083; diff --git a/cmd/traffic_manager/traffic_manager.cc b/cmd/traffic_manager/traffic_manager.cc index 1db3141f41d..7ec81cc3f91 100644 --- a/cmd/traffic_manager/traffic_manager.cc +++ b/cmd/traffic_manager/traffic_manager.cc @@ -59,7 +59,6 @@ #define FD_THROTTLE_HEADROOM (128 + 64) // TODO: consolidate with THROTTLE_FD_HEADROOM #define DIAGS_LOG_FILENAME "manager.log" - // These globals are still referenced directly by management API. LocalManager *lmgmt = NULL; FileManager *configFiles; @@ -730,7 +729,7 @@ main(int argc, const char **argv) lmgmt->processEventQueue(); lmgmt->pollMgmtProcessServer(); - // Handle rotation of output log (aka traffic.out) + // Handle rotation of output log (aka traffic.out) as well as DIAGS_LOG_FILENAME (aka manager.log) rotateLogs(); // Check for a SIGHUP diff --git a/doc/reference/configuration/records.config.en.rst b/doc/reference/configuration/records.config.en.rst index 8bee69435f6..702dad56e3d 100644 --- a/doc/reference/configuration/records.config.en.rst +++ b/doc/reference/configuration/records.config.en.rst @@ -221,8 +221,8 @@ A value of ``0`` means no signal will be sent. - ``0`` = disables output log rolling - ``1`` = enables output log rolling at specific intervals (specified with the - `proxy.config.output.logfile.rolling_interval_sec`_ variable). The "clock" starts ticking on Traffic Server boot - - ``2`` = enables output log rolling when the output log reaches a specific size (specified with the `proxy.config.output.logfile.rolling_size_mb`_ variable) + :ts:cv:`proxy.config.output.logfile.rolling_interval_sec` variable). The "clock" starts ticking on Traffic Server boot + - ``2`` = enables output log rolling when the output log reaches a specific size (specified with the :ts:cv:`proxy.config.output.logfile.rolling_size_mb` variable) .. ts:cv:: CONFIG proxy.config.output.logfile.rolling_interval_sec INT 3600 :reloadable: @@ -2256,8 +2256,8 @@ ssl TLS termination and certificate processing - ``0`` = disables diagnostics log rolling - ``1`` = enables diagnostics log rolling at specific intervals (specified with the - `proxy.config.diags.logfile.rolling_interval_sec`_ variable). The "clock" starts ticking on Traffic Server boot - - ``2`` = enables diagnostics log rolling when the diagnostics log reaches a specific size (specified with the `proxy.config.diags.logfile.rolling_size_mb`_ variable) + :ts:cv:`proxy.config.diags.logfile.rolling_interval_sec` variable). The "clock" starts ticking on Traffic Server boot + - ``2`` = enables diagnostics log rolling when the diagnostics log reaches a specific size (specified with the :ts:cv:`proxy.config.diags.logfile.rolling_size_mb` variable) .. ts:cv:: CONFIG proxy.config.diags.logfile.rolling_interval_sec INT 3600 :reloadable: diff --git a/iocore/eventsystem/test_Buffer.cc b/iocore/eventsystem/test_Buffer.cc index 06ccf619c60..aabd0ce7a87 100644 --- a/iocore/eventsystem/test_Buffer.cc +++ b/iocore/eventsystem/test_Buffer.cc @@ -97,7 +97,7 @@ init_diags(const char *bdt, const char *bat) BaseLogFile *blf = new BaseLogFile(diags_logpath); diags = new Diags(bdt, bat, blf); - if (blf && blf->m_fp == NULL) { + if (blf == NULL || blf->m_fp == NULL) { Warning("couldn't open diags log file '%s', " "will not log to this file", diags_logpath); diff --git a/iocore/eventsystem/test_Event.cc b/iocore/eventsystem/test_Event.cc index c7d58ac6a1e..3f2172ee4da 100644 --- a/iocore/eventsystem/test_Event.cc +++ b/iocore/eventsystem/test_Event.cc @@ -97,7 +97,7 @@ init_diags(const char *bdt, const char *bat) BaseLogFile *blf = new BaseLogFile(diags_logpath); diags = new Diags(bdt, bat, blf); - if (blf->m_fp == NULL) { + if (blf == NULL || blf->m_fp == NULL) { Warning("couldn't open diags log file '%s', " "will not log to this file", diags_logpath); diff --git a/lib/ts/BaseLogFile.cc b/lib/ts/BaseLogFile.cc index ea1477a0dae..76d5644deab 100644 --- a/lib/ts/BaseLogFile.cc +++ b/lib/ts/BaseLogFile.cc @@ -30,7 +30,7 @@ BaseLogFile::BaseLogFile(const char *name) : m_signature(0), m_has_signature(false) { init(name); - log_log_trace("exiting BaseLogFile constructor, m_name=%s, this=%p\n", (char *)m_name, this); + log_log_trace("exiting BaseLogFile constructor, m_name=%s, this=%p\n", m_name.get(), this); } /* @@ -40,7 +40,7 @@ BaseLogFile::BaseLogFile(const char *name) : m_signature(0), m_has_signature(fal BaseLogFile::BaseLogFile(const char *name, uint64_t sig) : m_signature(sig), m_has_signature(true) { init(name); - log_log_trace("exiting BaseLogFile signature constructor, m_name=%s, m_signature=%ld, this=%p\n", (char *)m_name, m_signature, + log_log_trace("exiting BaseLogFile signature constructor, m_name=%s, m_signature=%ld, this=%p\n", m_name.get(), m_signature, this); } @@ -52,7 +52,7 @@ BaseLogFile::BaseLogFile(const BaseLogFile ©) m_has_signature(copy.m_has_signature), m_name(ats_strdup(copy.m_name)), m_hostname(ats_strdup(copy.m_hostname)), m_is_regfile(false), m_is_init(copy.m_is_init), m_meta_info(NULL) { - log_log_trace("exiting BaseLogFile copy constructor, m_name=%s, this=%p\n", (char *)m_name, this); + log_log_trace("exiting BaseLogFile copy constructor, m_name=%s, this=%p\n", m_name.get(), this); } /* @@ -60,12 +60,12 @@ BaseLogFile::BaseLogFile(const BaseLogFile ©) */ BaseLogFile::~BaseLogFile() { - log_log_trace("entering BaseLogFile destructor, m_name=%s, this=%p\n", (char *)m_name, this); + log_log_trace("entering BaseLogFile destructor, m_name=%s, this=%p\n", m_name.get(), this); if (m_is_regfile) close_file(); else - log_log_trace("not a regular file, not closing, m_name=%s, this=%p\n", (char *)m_name, this); + log_log_trace("not a regular file, not closing, m_name=%s, this=%p\n", m_name.get(), this); log_log_trace("exiting BaseLogFile destructor, this=%p\n", this); } @@ -114,20 +114,20 @@ int BaseLogFile::roll(long interval_start, long interval_end) { // First, let's see if a roll is even needed. - if (m_name == NULL || !BaseLogFile::exists((char *)m_name)) { - log_log_trace("Roll not needed for %s; file doesn't exist\n", ((char *)m_name) ? (char *)m_name : "no_name\n"); + if (m_name == NULL || !BaseLogFile::exists(m_name.get())) { + log_log_trace("Roll not needed for %s; file doesn't exist\n", (m_name.get()) ? m_name.get() : "no_name\n"); return 0; } // Then, check if this object is backing a regular file if (!m_is_regfile) { - log_log_trace("Roll not needed for %s; not regular file\n", ((char *)m_name) ? (char *)m_name : "no_name\n"); + log_log_trace("Roll not needed for %s; not regular file\n", (m_name.get()) ? m_name.get() : "no_name\n"); return 0; } // Read meta info if needed (if file was not opened) if (!m_meta_info) { - m_meta_info = new BaseMetaInfo((char *)m_name); + m_meta_info = new BaseMetaInfo(m_name.get()); } // Create the new file name, which consists of a timestamp and rolled @@ -170,7 +170,7 @@ BaseLogFile::roll(long interval_start, long interval_end) // produce overlapping filenames (the problem is that we have // no easy way of keeping track of the timestamp of the first // transaction - log_log_trace("in BaseLogFile::roll(..) used else math starttime\n"); + log_log_trace("in BaseLogFile::roll(..), didn't use metadata starttime, used earlist available starttime\n"); if (interval_start == 0) start = m_start_time; else @@ -183,9 +183,8 @@ BaseLogFile::roll(long interval_start, long interval_end) // timestamp formats and create the rolled file name. timestamp_to_str((long)start, start_time_ext, sizeof(start_time_ext)); timestamp_to_str((long)end, end_time_ext, sizeof(start_time_ext)); - snprintf(roll_name, LOGFILE_ROLL_MAXPATHLEN, "%s%s%s.%s-%s%s", (char *)m_name, - ((char *)m_hostname ? LOGFILE_SEPARATOR_STRING : ""), ((char *)m_hostname ? (char *)m_hostname : ""), start_time_ext, - end_time_ext, LOGFILE_ROLLED_EXTENSION); + snprintf(roll_name, LOGFILE_ROLL_MAXPATHLEN, "%s%s%s.%s-%s%s", m_name.get(), (m_hostname.get() ? LOGFILE_SEPARATOR_STRING : ""), + (m_hostname.get() ? m_hostname.get() : ""), start_time_ext, end_time_ext, LOGFILE_ROLLED_EXTENSION); // It may be possible that the file we want to roll into already // exists. If so, then we need to add a version tag to the rolled @@ -195,17 +194,17 @@ BaseLogFile::roll(long interval_start, long interval_end) log_log_trace("The rolled file %s already exists; adding version " "tag %d to avoid clobbering the existing file.\n", roll_name, version); - snprintf(roll_name, LOGFILE_ROLL_MAXPATHLEN, "%s%s%s.%s-%s.%d%s", (char *)m_name, - ((char *)m_hostname ? LOGFILE_SEPARATOR_STRING : ""), ((char *)m_hostname ? (char *)m_hostname : ""), start_time_ext, + snprintf(roll_name, LOGFILE_ROLL_MAXPATHLEN, "%s%s%s.%s-%s.%d%s", m_name.get(), + (m_hostname.get() ? LOGFILE_SEPARATOR_STRING : ""), (m_hostname.get() ? m_hostname.get() : ""), start_time_ext, end_time_ext, version, LOGFILE_ROLLED_EXTENSION); ++version; } // It's now safe to rename the file. - if (::rename((char *)m_name, roll_name) < 0) { + if (::rename(m_name.get(), roll_name) < 0) { log_log_error("Traffic Server could not rename logfile %s to %s, error %d: " "%s.\n", - (char *)m_name, roll_name, errno, strerror(errno)); + m_name.get(), roll_name, errno, strerror(errno)); return 0; } @@ -213,7 +212,7 @@ BaseLogFile::roll(long interval_start, long interval_end) m_start_time = 0; m_bytes_written = 0; - log_log_trace("The logfile %s was rolled to %s.\n", (char *)m_name, roll_name); + log_log_trace("The logfile %s was rolled to %s.\n", m_name.get(), roll_name); return 1; } @@ -284,15 +283,15 @@ BaseLogFile::open_file(int perm) return LOG_FILE_NO_ERROR; } - if (!(char *)m_name) { + if (!m_name.get()) { log_log_error("BaseLogFile: m_name is NULL, aborting open_file()\n"); return LOG_FILE_COULD_NOT_OPEN_FILE; - } else if (!strcmp((char *)m_name, "stdout")) { + } else if (!strcmp(m_name.get(), "stdout")) { log_log_trace("BaseLogFile: stdout opened\n"); m_fp = stdout; m_is_init = true; return LOG_FILE_NO_ERROR; - } else if (!strcmp((char *)m_name, "stderr")) { + } else if (!strcmp(m_name.get(), "stderr")) { log_log_trace("BaseLogFile: stderr opened\n"); m_fp = stderr; m_is_init = true; @@ -304,31 +303,31 @@ BaseLogFile::open_file(int perm) // Check to see if the file exists BEFORE we try to open it, since // opening it will also create it. - bool file_exists = BaseLogFile::exists((char *)m_name); + bool file_exists = BaseLogFile::exists(m_name.get()); if (file_exists) { if (!m_meta_info) { // This object must be fresh since it has not built its MetaInfo // so we create a new MetaInfo object that will read right away // (in the constructor) the corresponding metafile - m_meta_info = new BaseMetaInfo((char *)m_name); + m_meta_info = new BaseMetaInfo(m_name.get()); } } else { // The log file does not exist, so we create a new MetaInfo object // which will save itself to disk right away (in the constructor) if (m_has_signature) - m_meta_info = new BaseMetaInfo((char *)m_name, (long)time(0), m_signature); + m_meta_info = new BaseMetaInfo(m_name.get(), (long)time(0), m_signature); else - m_meta_info = new BaseMetaInfo((char *)m_name, (long)time(0)); + m_meta_info = new BaseMetaInfo(m_name.get(), (long)time(0)); } // open actual log file (not metainfo) - log_log_trace("BaseLogFile: attempting to open %s\n", (char *)m_name); - m_fp = fopen((char *)m_name, "a+"); + log_log_trace("BaseLogFile: attempting to open %s\n", m_name.get()); + m_fp = fopen(m_name.get(), "a+"); // error check if (!m_fp) { - log_log_error("Error opening log file %s: %s\n", (char *)m_name, strerror(errno)); + log_log_error("Error opening log file %s: %s\n", m_name.get(), strerror(errno)); log_log_error("Actual error: %s\n", (errno == EINVAL ? "einval" : "something else")); return LOG_FILE_COULD_NOT_OPEN_FILE; } @@ -336,14 +335,14 @@ BaseLogFile::open_file(int perm) // set permissions if necessary if (perm != -1) { // means LogFile passed in some permissions we need to set - if (chmod((char *)m_name, perm) != 0) - log_log_error("Error changing logfile=%s permissions: %s\n", (char *)m_name, strerror(errno)); + if (chmod(m_name.get(), perm) != 0) + log_log_error("Error changing logfile=%s permissions: %s\n", m_name.get(), strerror(errno)); } // set m_bytes_written to force the rolling based on filesize. m_bytes_written = fseek(m_fp, 0, SEEK_CUR); - log_log_trace("BaseLogFile %s is now open (fd=%d)\n", (char *)m_name, fileno(m_fp)); + log_log_trace("BaseLogFile %s is now open (fd=%d)\n", m_name.get(), fileno(m_fp)); m_is_init = true; return LOG_FILE_NO_ERROR; } @@ -356,7 +355,7 @@ BaseLogFile::close_file() { if (is_open()) { fclose(m_fp); - log_log_trace("BaseLogFile %s is closed\n", (char *)m_name); + log_log_trace("BaseLogFile %s is closed\n", m_name.get()); m_fp = NULL; m_is_init = false; } @@ -368,7 +367,6 @@ BaseLogFile::close_file() void BaseLogFile::change_name(const char *new_name) { - ats_free(m_name); m_name = ats_strdup(new_name); } diff --git a/lib/ts/BaseLogFile.h b/lib/ts/BaseLogFile.h index c7ba90bfce6..23081180843 100644 --- a/lib/ts/BaseLogFile.h +++ b/lib/ts/BaseLogFile.h @@ -46,6 +46,7 @@ #define LOGFILE_DEFAULT_PERMS (0644) #define LOGFILE_ROLL_MAXPATHLEN 4096 #define BASELOGFILE_DEBUG_MODE 0 // change this to 1 to enable debug messages + // TODO find a way to enable this from autotools typedef enum { LL_Debug = 0, // process does not die diff --git a/lib/ts/Diags.h b/lib/ts/Diags.h index 8038ce7daa5..ac39f13a949 100644 --- a/lib/ts/Diags.h +++ b/lib/ts/Diags.h @@ -36,7 +36,6 @@ #define __DIAGS_H___ #include -#include "ink_error.h" #include "ink_mutex.h" #include "Regex.h" #include "ink_apidefs.h" diff --git a/proxy/Main.cc b/proxy/Main.cc index 432196ddd22..2902eb40839 100644 --- a/proxy/Main.cc +++ b/proxy/Main.cc @@ -124,10 +124,6 @@ static void *mgmt_restart_shutdown_callback(void *, char *, int data_len); static void *mgmt_storage_device_cmd_callback(void *x, char *data, int len); static void init_ssl_ctx_callback(void *ctx, bool server); -// XXX rename these to be more descriptive -void stdout_log_callback(void *); -void stderr_log_callback(void *); - static int num_of_net_threads = ink_number_of_processors(); static int num_of_udp_threads = 0; static int num_accept_threads = 0; @@ -259,7 +255,7 @@ class SignalContinuation : public Continuation snap = now; } else if (sigusr2_received) { sigusr2_received = false; - Debug("log", "received SIGUSR2, reloading traffic.outl\n"); + Debug("log", "received SIGUSR2, reloading traffic.out"); // reload output logfile (file is usually called traffic.out) diags->set_stdout_output(bind_stdout); diags->set_stderr_output(bind_stderr); diff --git a/proxy/Makefile.am b/proxy/Makefile.am index 1b2023b18af..01602946c3e 100644 --- a/proxy/Makefile.am +++ b/proxy/Makefile.am @@ -46,7 +46,7 @@ AM_CPPFLAGS = \ -I$(top_srcdir)/mgmt \ -I$(top_srcdir)/mgmt/utils \ -I$(top_srcdir)/proxy/api/ts \ - -I$(top_srcdir)/lib + -I$(top_srcdir)/lib \ @OPENSSL_INCLUDES@ # NOTE: it is safe to use AM_LDFLAGS here because we are only building executables. If we start diff --git a/proxy/logging/LogFile.cc b/proxy/logging/LogFile.cc index 954d570ee26..c9c40ce9b57 100644 --- a/proxy/logging/LogFile.cc +++ b/proxy/logging/LogFile.cc @@ -121,6 +121,8 @@ void LogFile::change_name(const char *new_name) { ats_free(m_name); + if (m_log) + m_log->change_name(new_name); m_name = ats_strdup(new_name); } @@ -224,6 +226,7 @@ LogFile::close_file() } else if (m_log) { m_log->close_file(); Debug("log-file", "LogFile %s is closed", m_log->get_name()); + delete m_log; m_log = NULL; } else { Warning("LogFile %s is open but was not closed", m_name);