1 /** @file
2 
3   This file implements the LogConfig object.
4 
5   @section license License
6 
7   Licensed to the Apache Software Foundation (ASF) under one
8   or more contributor license agreements.  See the NOTICE file
9   distributed with this work for additional information
10   regarding copyright ownership.  The ASF licenses this file
11   to you under the Apache License, Version 2.0 (the
12   "License"); you may not use this file except in compliance
13   with the License.  You may obtain a copy of the License at
14 
15       http://www.apache.org/licenses/LICENSE-2.0
16 
17   Unless required by applicable law or agreed to in writing, software
18   distributed under the License is distributed on an "AS IS" BASIS,
19   WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
20   See the License for the specific language governing permissions and
21   limitations under the License.
22  */
23 
24 #include "tscore/ink_platform.h"
25 #include "tscore/I_Layout.h"
26 
27 #ifdef HAVE_SYS_PARAM_H
28 #include <sys/param.h>
29 #endif
30 
31 #include <memory>
32 
33 #include "tscore/ink_platform.h"
34 #include "tscore/ink_file.h"
35 
36 #include "tscore/List.h"
37 #include "tscore/Filenames.h"
38 
39 #include "Log.h"
40 #include "LogField.h"
41 #include "LogFilter.h"
42 #include "LogFormat.h"
43 #include "LogFile.h"
44 #include "LogBuffer.h"
45 #include "LogObject.h"
46 #include "LogConfig.h"
47 #include "LogUtils.h"
48 #include "tscore/SimpleTokenizer.h"
49 
50 #include "YamlLogConfig.h"
51 
52 #define DISK_IS_CONFIG_FULL_MESSAGE                    \
53   "Access logging to local log directory suspended - " \
54   "configured space allocation exhausted."
55 #define DISK_IS_ACTUAL_FULL_MESSAGE                    \
56   "Access logging to local log directory suspended - " \
57   "no more space on the logging partition."
58 #define DISK_IS_CONFIG_LOW_MESSAGE                     \
59   "Access logging to local log directory suspended - " \
60   "configured space allocation almost exhausted."
61 #define DISK_IS_ACTUAL_LOW_MESSAGE "Access logging to local log directory suspended - partition space is low."
62 
63 #define PARTITION_HEADROOM_MB 10
64 #define DIAGS_LOG_FILENAME "diags.log"
65 #define MANAGER_LOG_FILENAME "manager.log"
66 
67 void
setup_default_values()68 LogConfig::setup_default_values()
69 {
70   const unsigned int bufSize = 512;
71   char name[bufSize];
72   if (!gethostname(name, bufSize)) {
73     ink_strlcpy(name, "unknown_host_name", sizeof(name));
74   }
75   hostname = ats_strdup(name);
76 
77   log_buffer_size       = static_cast<int>(10 * LOG_KILOBYTE);
78   max_secs_per_buffer   = 5;
79   max_space_mb_for_logs = 100;
80   max_space_mb_headroom = 10;
81   logfile_perm          = 0644;
82   logfile_dir           = ats_strdup(".");
83 
84   preproc_threads = 1;
85 
86   rolling_enabled          = Log::NO_ROLLING;
87   rolling_interval_sec     = 86400; // 24 hours
88   rolling_offset_hr        = 0;
89   rolling_size_mb          = 10;
90   rolling_max_count        = 0;
91   rolling_allow_empty      = false;
92   auto_delete_rolled_files = true;
93   roll_log_files_now       = false;
94 
95   sampling_frequency   = 1;
96   file_stat_frequency  = 16;
97   space_used_frequency = 900;
98 
99   ascii_buffer_size         = 4 * 9216;
100   max_line_size             = 9216; // size of pipe buffer for SunOS 5.6
101   logbuffer_max_iobuf_index = BUFFER_SIZE_INDEX_32K;
102 }
103 
reconfigure_mgmt_variables(ts::MemSpan<void>)104 void LogConfig::reconfigure_mgmt_variables(ts::MemSpan<void>)
105 {
106   Note("received log reconfiguration event, rolling now");
107   Log::config->roll_log_files_now = true;
108 }
109 
110 void
register_rolled_log_auto_delete(std::string_view logname,int rolling_min_count)111 LogConfig::register_rolled_log_auto_delete(std::string_view logname, int rolling_min_count)
112 {
113   if (!auto_delete_rolled_files) {
114     // Nothing to do if auto-deletion is not configured.
115     return;
116   }
117 
118   Debug("logspace", "Registering rotated log deletion for %s with min roll count %d", std::string(logname).c_str(),
119         rolling_min_count);
120   rolledLogDeleter.register_log_type_for_deletion(logname, rolling_min_count);
121 }
122 
123 void
read_configuration_variables()124 LogConfig::read_configuration_variables()
125 {
126   int val;
127   char *ptr;
128 
129   val = static_cast<int>(REC_ConfigReadInteger("proxy.config.log.log_buffer_size"));
130   if (val > 0) {
131     log_buffer_size = val;
132   }
133 
134   val = static_cast<int>(REC_ConfigReadInteger("proxy.config.log.max_secs_per_buffer"));
135   if (val > 0) {
136     max_secs_per_buffer = val;
137   }
138 
139   val = static_cast<int>(REC_ConfigReadInteger("proxy.config.log.max_space_mb_for_logs"));
140   if (val > 0) {
141     max_space_mb_for_logs = val;
142   }
143 
144   val = static_cast<int>(REC_ConfigReadInteger("proxy.config.log.max_space_mb_headroom"));
145   if (val > 0) {
146     max_space_mb_headroom = val;
147   }
148 
149   val = static_cast<int>(REC_ConfigReadInteger("proxy.config.log.io.max_buffer_index"));
150   if (val > 0) {
151     logbuffer_max_iobuf_index = val;
152   }
153 
154   ptr                     = REC_ConfigReadString("proxy.config.log.logfile_perm");
155   int logfile_perm_parsed = ink_fileperm_parse(ptr);
156   if (logfile_perm_parsed != -1) {
157     logfile_perm = logfile_perm_parsed;
158   }
159   ats_free(ptr);
160 
161   ptr = REC_ConfigReadString("proxy.config.log.hostname");
162   if (ptr != nullptr) {
163     ats_free(hostname);
164     hostname = ptr;
165   }
166 
167   ats_free(logfile_dir);
168   logfile_dir = ats_stringdup(RecConfigReadLogDir());
169 
170   if (access(logfile_dir, R_OK | W_OK | X_OK) == -1) {
171     // Try 'system_root_dir/var/log/trafficserver' directory
172     fprintf(stderr, "unable to access log directory '%s': %d, %s\n", logfile_dir, errno, strerror(errno));
173     fprintf(stderr, "please set 'proxy.config.log.logfile_dir'\n");
174     ::exit(1);
175   }
176 
177   val = static_cast<int>(REC_ConfigReadInteger("proxy.config.log.preproc_threads"));
178   if (val > 0 && val <= 128) {
179     preproc_threads = val;
180   }
181 
182   // ROLLING
183 
184   // we don't check for valid values of rolling_enabled, rolling_interval_sec,
185   // rolling_offset_hr, or rolling_size_mb because the LogObject takes care of this
186   //
187   rolling_interval_sec = static_cast<int>(REC_ConfigReadInteger("proxy.config.log.rolling_interval_sec"));
188   rolling_offset_hr    = static_cast<int>(REC_ConfigReadInteger("proxy.config.log.rolling_offset_hr"));
189   rolling_size_mb      = static_cast<int>(REC_ConfigReadInteger("proxy.config.log.rolling_size_mb"));
190   rolling_min_count    = static_cast<int>(REC_ConfigReadInteger("proxy.config.log.rolling_min_count"));
191   val                  = static_cast<int>(REC_ConfigReadInteger("proxy.config.log.rolling_enabled"));
192   if (LogRollingEnabledIsValid(val)) {
193     rolling_enabled = static_cast<Log::RollingEnabledValues>(val);
194   } else {
195     Warning("invalid value '%d' for '%s', disabling log rolling", val, "proxy.config.log.rolling_enabled");
196     rolling_enabled = Log::NO_ROLLING;
197   }
198 
199   val                      = static_cast<int>(REC_ConfigReadInteger("proxy.config.log.auto_delete_rolled_files"));
200   auto_delete_rolled_files = (val > 0);
201 
202   val                 = static_cast<int>(REC_ConfigReadInteger("proxy.config.log.rolling_allow_empty"));
203   rolling_allow_empty = (val > 0);
204 
205   // Read in min_count control values for auto deletion
206   if (auto_delete_rolled_files) {
207     // The majority of register_rolled_log_auto_delete() updates come in
208     // through LogObject. However, not all ATS logs are managed by LogObject.
209     // The following register these other core logs for log rotation deletion.
210 
211     // For diagnostic logs
212     val = static_cast<int>(REC_ConfigReadInteger("proxy.config.diags.logfile.rolling_min_count"));
213     register_rolled_log_auto_delete(DIAGS_LOG_FILENAME, val);
214     register_rolled_log_auto_delete(MANAGER_LOG_FILENAME, val);
215 
216     // For traffic.out
217     char *configured_name(REC_ConfigReadString("proxy.config.output.logfile"));
218     const char *traffic_logname = configured_name ? configured_name : "traffic.out";
219     val                         = static_cast<int>(REC_ConfigReadInteger("proxy.config.output.logfile.rolling_min_count"));
220     register_rolled_log_auto_delete(traffic_logname, val);
221 
222     rolling_max_count = static_cast<int>(REC_ConfigReadInteger("proxy.config.log.rolling_max_count"));
223 
224     ats_free(configured_name);
225   }
226   // PERFORMANCE
227   val = static_cast<int>(REC_ConfigReadInteger("proxy.config.log.sampling_frequency"));
228   if (val > 0) {
229     sampling_frequency = val;
230   }
231 
232   val = static_cast<int>(REC_ConfigReadInteger("proxy.config.log.file_stat_frequency"));
233   if (val > 0) {
234     file_stat_frequency = val;
235   }
236 
237   val = static_cast<int>(REC_ConfigReadInteger("proxy.config.log.space_used_frequency"));
238   if (val > 0) {
239     space_used_frequency = val;
240   }
241 
242   // ASCII BUFFER
243   val = static_cast<int>(REC_ConfigReadInteger("proxy.config.log.ascii_buffer_size"));
244   if (val > 0) {
245     ascii_buffer_size = val;
246   }
247 
248   val = static_cast<int>(REC_ConfigReadInteger("proxy.config.log.max_line_size"));
249   if (val > 0) {
250     max_line_size = val;
251   }
252 }
253 
254 /*-------------------------------------------------------------------------
255   LogConfig::LogConfig
256 
257   Read the logging configuration variables from the config file and
258   initialize the LogConfig member variables.  Assign some meaningful
259   default value if we get garbage back from the config file.
260   -------------------------------------------------------------------------*/
261 
262 // TODO: Is UINT_MAX here really correct?
LogConfig()263 LogConfig::LogConfig() : m_partition_space_left(static_cast<int64_t>(UINT_MAX))
264 {
265   // Setup the default values for all LogConfig public variables so that
266   // a LogConfig object is valid upon return from the constructor even
267   // if no configuration file is read
268   //
269   setup_default_values();
270 }
271 
272 /*-------------------------------------------------------------------------
273   LogConfig::~LogConfig
274 
275   Delete all config variable strings.
276   -------------------------------------------------------------------------*/
277 
~LogConfig()278 LogConfig::~LogConfig()
279 {
280   ats_free(logfile_dir);
281 }
282 
283 /*-------------------------------------------------------------------------
284   LogConfig::init
285   -------------------------------------------------------------------------*/
286 
287 void
init(LogConfig * prev_config)288 LogConfig::init(LogConfig *prev_config)
289 {
290   LogObject *errlog = nullptr;
291 
292   ink_assert(!initialized);
293 
294   update_space_used();
295 
296   // create log objects
297   //
298   if (Log::transaction_logging_enabled()) {
299     setup_log_objects();
300   }
301 
302   // ----------------------------------------------------------------------
303   // Construct a new error log object candidate.
304   if (Log::error_logging_enabled()) {
305     std::unique_ptr<LogFormat> fmt(MakeTextLogFormat("error"));
306 
307     Debug("log", "creating predefined error log object");
308 
309     errlog = new LogObject(this, fmt.get(), logfile_dir, "error.log", LOG_FILE_ASCII, nullptr, rolling_enabled, preproc_threads,
310                            rolling_interval_sec, rolling_offset_hr, rolling_size_mb, /* auto_created */ false, rolling_max_count,
311                            rolling_min_count);
312 
313     log_object_manager.manage_object(errlog);
314     errlog->set_fmt_timestamps();
315   } else {
316     Log::error_log = nullptr;
317   }
318 
319   if (prev_config) {
320     // Transfer objects from previous configuration.
321     transfer_objects(prev_config);
322 
323     // After transferring objects, we are going to keep either the new error log or the old one. Figure out
324     // which one we are keeping and make that the global ...
325     if (Log::error_log) {
326       errlog = this->log_object_manager.find_by_format_name(Log::error_log->m_format->name());
327     }
328   }
329 
330   ink_atomic_swap(&Log::error_log, errlog);
331 
332   initialized = true;
333 }
334 
335 /*-------------------------------------------------------------------------
336   LogConfig::display
337 
338   Dump the values for the current LogConfig object.
339   -------------------------------------------------------------------------*/
340 
341 void
display(FILE * fd)342 LogConfig::display(FILE *fd)
343 {
344   fprintf(fd, "-----------------------------\n");
345   fprintf(fd, "--- Logging Configuration ---\n");
346   fprintf(fd, "-----------------------------\n");
347   fprintf(fd, "Config variables:\n");
348   fprintf(fd, "   log_buffer_size = %d\n", log_buffer_size);
349   fprintf(fd, "   max_secs_per_buffer = %d\n", max_secs_per_buffer);
350   fprintf(fd, "   max_space_mb_for_logs = %d\n", max_space_mb_for_logs);
351   fprintf(fd, "   max_space_mb_headroom = %d\n", max_space_mb_headroom);
352   fprintf(fd, "   hostname = %s\n", hostname);
353   fprintf(fd, "   logfile_dir = %s\n", logfile_dir);
354   fprintf(fd, "   logfile_perm = 0%o\n", logfile_perm);
355 
356   fprintf(fd, "   preproc_threads = %d\n", preproc_threads);
357   fprintf(fd, "   rolling_enabled = %d\n", rolling_enabled);
358   fprintf(fd, "   rolling_interval_sec = %d\n", rolling_interval_sec);
359   fprintf(fd, "   rolling_offset_hr = %d\n", rolling_offset_hr);
360   fprintf(fd, "   rolling_size_mb = %d\n", rolling_size_mb);
361   fprintf(fd, "   rolling_min_count = %d\n", rolling_min_count);
362   fprintf(fd, "   rolling_max_count = %d\n", rolling_max_count);
363   fprintf(fd, "   rolling_allow_empty = %d\n", rolling_allow_empty);
364   fprintf(fd, "   auto_delete_rolled_files = %d\n", auto_delete_rolled_files);
365   fprintf(fd, "   sampling_frequency = %d\n", sampling_frequency);
366   fprintf(fd, "   file_stat_frequency = %d\n", file_stat_frequency);
367   fprintf(fd, "   space_used_frequency = %d\n", space_used_frequency);
368   fprintf(fd, "   logbuffer_max_iobuf_index = %d\n", logbuffer_max_iobuf_index);
369 
370   fprintf(fd, "\n");
371   fprintf(fd, "************ Log Objects (%u objects) ************\n", log_object_manager.get_num_objects());
372   log_object_manager.display(fd);
373 
374   fprintf(fd, "************ Filter List (%u filters) ************\n", filter_list.count());
375   filter_list.display(fd);
376 
377   fprintf(fd, "************ Format List (%u formats) ************\n", format_list.count());
378   format_list.display(fd);
379 }
380 
381 //-----------------------------------------------------------------------------
382 // setup_log_objects
383 //
384 // Construct: All custom objects.
385 //
386 // Upon return from this function:
387 // - global_object_list has the aforementioned objects
388 // - global_filter_list has all custom filters
389 //
390 void
setup_log_objects()391 LogConfig::setup_log_objects()
392 {
393   Debug("log", "creating objects...");
394 
395   filter_list.clear();
396 
397   // Evaluate logging.yaml to construct the custom log objects.
398   evaluate_config();
399 
400   // Open local pipes so readers can see them.
401   log_object_manager.open_local_pipes();
402 
403   if (is_debug_tag_set("log")) {
404     log_object_manager.display();
405   }
406 }
407 
408 /*-------------------------------------------------------------------------
409   LogConfig::reconfigure
410 
411   This is the manager callback for any logging config variable change.
412   Since we want to access the config variables to build a new config
413   object, but can't from this function (big lock technology in the
414   manager), we'll just set a flag and call the real reconfiguration
415   function from the logging thread.
416   -------------------------------------------------------------------------*/
417 
418 int
reconfigure(const char *,RecDataT,RecData,void *)419 LogConfig::reconfigure(const char * /* name ATS_UNUSED */, RecDataT /* data_type ATS_UNUSED */, RecData /* data ATS_UNUSED */,
420                        void * /* cookie ATS_UNUSED */)
421 {
422   Debug("log-config", "Reconfiguration request accepted");
423   Log::config->reconfiguration_needed = true;
424   return 0;
425 }
426 
427 /*-------------------------------------------------------------------------
428   LogConfig::register_config_callbacks
429 
430   This static function is called by Log::init to register the config update
431   function for each of the logging configuration variables.
432   -------------------------------------------------------------------------*/
433 
434 void
register_config_callbacks()435 LogConfig::register_config_callbacks()
436 {
437   static const char *names[] = {
438     "proxy.config.log.log_buffer_size",       "proxy.config.log.max_secs_per_buffer", "proxy.config.log.max_space_mb_for_logs",
439     "proxy.config.log.max_space_mb_headroom", "proxy.config.log.logfile_perm",        "proxy.config.log.hostname",
440     "proxy.config.log.logfile_dir",           "proxy.config.log.rolling_enabled",     "proxy.config.log.rolling_interval_sec",
441     "proxy.config.log.rolling_offset_hr",     "proxy.config.log.rolling_size_mb",     "proxy.config.log.auto_delete_rolled_files",
442     "proxy.config.log.rolling_max_count",     "proxy.config.log.rolling_allow_empty", "proxy.config.log.config.filename",
443     "proxy.config.log.sampling_frequency",    "proxy.config.log.file_stat_frequency", "proxy.config.log.space_used_frequency",
444     "proxy.config.log.io.max_buffer_index",
445   };
446 
447   for (unsigned i = 0; i < countof(names); ++i) {
448     REC_RegisterConfigUpdateFunc(names[i], &LogConfig::reconfigure, nullptr);
449   }
450 }
451 
452 /*-------------------------------------------------------------------------
453   LogConfig::register_stat_callbacks
454 
455   This static function is called by Log::init to register the stat update
456   function for each of the logging stats variables.
457   -------------------------------------------------------------------------*/
458 
459 void
register_stat_callbacks()460 LogConfig::register_stat_callbacks()
461 {
462   //
463   // events
464   //
465   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.event_log_error_ok", RECD_COUNTER, RECP_PERSISTENT,
466                      (int)log_stat_event_log_error_ok_stat, RecRawStatSyncCount);
467   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.event_log_error_skip", RECD_COUNTER, RECP_PERSISTENT,
468                      (int)log_stat_event_log_error_skip_stat, RecRawStatSyncCount);
469   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.event_log_error_aggr", RECD_COUNTER, RECP_PERSISTENT,
470                      (int)log_stat_event_log_error_aggr_stat, RecRawStatSyncCount);
471   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.event_log_error_full", RECD_COUNTER, RECP_PERSISTENT,
472                      (int)log_stat_event_log_error_full_stat, RecRawStatSyncCount);
473   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.event_log_error_fail", RECD_COUNTER, RECP_PERSISTENT,
474                      (int)log_stat_event_log_error_fail_stat, RecRawStatSyncCount);
475   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.event_log_access_ok", RECD_COUNTER, RECP_PERSISTENT,
476                      (int)log_stat_event_log_access_ok_stat, RecRawStatSyncCount);
477   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.event_log_access_skip", RECD_COUNTER, RECP_PERSISTENT,
478                      (int)log_stat_event_log_access_skip_stat, RecRawStatSyncCount);
479   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.event_log_access_aggr", RECD_COUNTER, RECP_PERSISTENT,
480                      (int)log_stat_event_log_access_aggr_stat, RecRawStatSyncCount);
481   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.event_log_access_full", RECD_COUNTER, RECP_PERSISTENT,
482                      (int)log_stat_event_log_access_full_stat, RecRawStatSyncCount);
483   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.event_log_access_fail", RECD_COUNTER, RECP_PERSISTENT,
484                      (int)log_stat_event_log_access_fail_stat, RecRawStatSyncCount);
485   //
486   // number vs bytes of logs
487   //
488   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.num_sent_to_network", RECD_COUNTER, RECP_PERSISTENT,
489                      (int)log_stat_num_sent_to_network_stat, RecRawStatSyncSum);
490   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.num_lost_before_sent_to_network", RECD_COUNTER, RECP_PERSISTENT,
491                      (int)log_stat_num_lost_before_sent_to_network_stat, RecRawStatSyncSum);
492   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.num_received_from_network", RECD_COUNTER, RECP_PERSISTENT,
493                      (int)log_stat_num_received_from_network_stat, RecRawStatSyncSum);
494   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.num_flush_to_disk", RECD_COUNTER, RECP_PERSISTENT,
495                      (int)log_stat_num_flush_to_disk_stat, RecRawStatSyncSum);
496   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.num_lost_before_flush_to_disk", RECD_COUNTER, RECP_PERSISTENT,
497                      (int)log_stat_num_lost_before_flush_to_disk_stat, RecRawStatSyncSum);
498   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.bytes_lost_before_preproc", RECD_INT, RECP_PERSISTENT,
499                      (int)log_stat_bytes_lost_before_preproc_stat, RecRawStatSyncSum);
500   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.bytes_sent_to_network", RECD_INT, RECP_PERSISTENT,
501                      (int)log_stat_bytes_sent_to_network_stat, RecRawStatSyncSum);
502   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.bytes_lost_before_sent_to_network", RECD_INT, RECP_PERSISTENT,
503                      (int)log_stat_bytes_lost_before_sent_to_network_stat, RecRawStatSyncSum);
504   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.bytes_received_from_network", RECD_INT, RECP_PERSISTENT,
505                      (int)log_stat_bytes_received_from_network_stat, RecRawStatSyncSum);
506   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.bytes_flush_to_disk", RECD_INT, RECP_PERSISTENT,
507                      (int)log_stat_bytes_flush_to_disk_stat, RecRawStatSyncSum);
508   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.bytes_lost_before_flush_to_disk", RECD_INT, RECP_PERSISTENT,
509                      (int)log_stat_bytes_lost_before_flush_to_disk_stat, RecRawStatSyncSum);
510   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.bytes_written_to_disk", RECD_INT, RECP_PERSISTENT,
511                      (int)log_stat_bytes_written_to_disk_stat, RecRawStatSyncSum);
512   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.bytes_lost_before_written_to_disk", RECD_INT, RECP_PERSISTENT,
513                      (int)log_stat_bytes_lost_before_written_to_disk_stat, RecRawStatSyncSum);
514   //
515   // I/O
516   //
517   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.log_files_open", RECD_COUNTER, RECP_NON_PERSISTENT,
518                      (int)log_stat_log_files_open_stat, RecRawStatSyncSum);
519   RecRegisterRawStat(log_rsb, RECT_PROCESS, "proxy.process.log.log_files_space_used", RECD_INT, RECP_NON_PERSISTENT,
520                      (int)log_stat_log_files_space_used_stat, RecRawStatSyncSum);
521 }
522 
523 /*-------------------------------------------------------------------------
524   LogConfig::register_mgmt_callbacks
525 
526   This static function is called by Log::init to register the mgmt callback
527   function for each of the logging mgmt messages.
528   -------------------------------------------------------------------------*/
529 
530 void
register_mgmt_callbacks()531 LogConfig::register_mgmt_callbacks()
532 {
533   RecRegisterManagerCb(REC_EVENT_ROLL_LOG_FILES, &LogConfig::reconfigure_mgmt_variables);
534 }
535 
536 /*-------------------------------------------------------------------------
537   LogConfig::space_to_write
538 
539   This function returns true if there is enough disk space to write the
540   given number of bytes, false otherwise.
541   -------------------------------------------------------------------------*/
542 
543 bool
space_to_write(int64_t bytes_to_write) const544 LogConfig::space_to_write(int64_t bytes_to_write) const
545 {
546   int64_t config_space, partition_headroom;
547   int64_t logical_space_used, physical_space_left;
548   bool space;
549 
550   config_space       = static_cast<int64_t>(get_max_space_mb()) * LOG_MEGABYTE;
551   partition_headroom = static_cast<int64_t>(PARTITION_HEADROOM_MB) * LOG_MEGABYTE;
552 
553   logical_space_used  = m_space_used + bytes_to_write;
554   physical_space_left = m_partition_space_left - bytes_to_write;
555 
556   space = ((logical_space_used < config_space) && (physical_space_left > partition_headroom));
557 
558   Debug("logspace",
559         "logical space used %" PRId64 ", configured space %" PRId64 ", physical space left %" PRId64 ", partition headroom %" PRId64
560         ", space %s available",
561         logical_space_used, config_space, physical_space_left, partition_headroom, space ? "is" : "is not");
562 
563   return space;
564 }
565 
566 /*-------------------------------------------------------------------------
567   LogConfig::update_space_used
568 
569   Update the m_space_used variable by reading the logging dir and counting
570   the total bytes being occupied by files.  If we've used too much space
571   (space_used > max_space - headroom) then start deleting some files (if
572   auto_delete_rolled_files is set) to make room. Finally, update the
573   space_used stat.
574 
575   This routine will only be executed SINGLE-THREADED, either by the main
576   thread when a LogConfig is initialized, or by the event thread during the
577   periodic space check.
578   -------------------------------------------------------------------------*/
579 
580 void
update_space_used()581 LogConfig::update_space_used()
582 {
583   // no need to update space used if log directory is inaccessible
584   //
585   if (m_log_directory_inaccessible) {
586     return;
587   }
588 
589   int64_t total_space_used, partition_space_left;
590   char path[MAXPATHLEN];
591   int sret;
592   struct dirent *entry;
593   struct stat sbuf;
594   DIR *ld;
595 
596   // check if logging directory has been specified
597   //
598   if (!logfile_dir) {
599     const char *msg = "Logging directory not specified";
600     Error("%s", msg);
601     LogUtils::manager_alarm(LogUtils::LOG_ALARM_ERROR, "%s", msg);
602     m_log_directory_inaccessible = true;
603     return;
604   }
605 
606   // check if logging directory exists and is searchable readable & writable
607   int err;
608   do {
609     err = access(logfile_dir, R_OK | W_OK | X_OK);
610   } while ((err < 0) && (errno == EINTR));
611 
612   if (err < 0) {
613     const char *msg = "Error accessing logging directory %s: %s.";
614     Error(msg, logfile_dir, strerror(errno));
615     LogUtils::manager_alarm(LogUtils::LOG_ALARM_ERROR, msg, logfile_dir, strerror(errno));
616     m_log_directory_inaccessible = true;
617     return;
618   }
619 
620   ld = ::opendir(logfile_dir);
621   if (ld == nullptr) {
622     const char *msg = "Error opening logging directory %s to perform a space check: %s.";
623     Error(msg, logfile_dir, strerror(errno));
624     LogUtils::manager_alarm(LogUtils::LOG_ALARM_ERROR, msg, logfile_dir, strerror(errno));
625     m_log_directory_inaccessible = true;
626     return;
627   }
628 
629   total_space_used = 0LL;
630 
631   while ((entry = readdir(ld))) {
632     snprintf(path, MAXPATHLEN, "%s/%s", logfile_dir, entry->d_name);
633 
634     sret = ::stat(path, &sbuf);
635     if (sret != -1 && S_ISREG(sbuf.st_mode)) {
636       total_space_used += static_cast<int64_t>(sbuf.st_size);
637 
638       if (auto_delete_rolled_files && LogFile::rolled_logfile(entry->d_name)) {
639         rolledLogDeleter.consider_for_candidacy(path, sbuf.st_size, sbuf.st_mtime);
640       }
641     }
642   }
643 
644   ::closedir(ld);
645 
646   //
647   // Now check the partition to see if there is enough *actual* space.
648   //
649   partition_space_left = m_partition_space_left;
650 
651   struct statvfs fs;
652 
653   if (::statvfs(logfile_dir, &fs) >= 0) {
654     partition_space_left = static_cast<int64_t>(fs.f_bavail) * static_cast<int64_t>(fs.f_bsize);
655   }
656 
657   //
658   // Update the config variables for space used/left
659   //
660   m_space_used           = total_space_used;
661   m_partition_space_left = partition_space_left;
662   RecSetRawStatSum(log_rsb, log_stat_log_files_space_used_stat, m_space_used);
663   RecSetRawStatCount(log_rsb, log_stat_log_files_space_used_stat, 1);
664 
665   Debug("logspace", "%" PRId64 " bytes being used for logs", m_space_used);
666   Debug("logspace", "%" PRId64 " bytes left on partition", m_partition_space_left);
667 
668   //
669   // Now that we have an accurate picture of the amount of space being
670   // used by logging, we can see if we're running low on space.  If so,
671   // we might consider deleting some files that are stored in the
672   // candidate array.
673   //
674   // To delete oldest files first, we'll sort our candidate array by
675   // timestamps, making the oldest files first in the array (thus first
676   // selected).
677   //
678 
679   int64_t max_space = static_cast<int64_t>(get_max_space_mb()) * LOG_MEGABYTE;
680   int64_t headroom  = static_cast<int64_t>(max_space_mb_headroom) * LOG_MEGABYTE;
681 
682   if (!space_to_write(headroom)) {
683     Debug("logspace", "headroom reached, trying to clear space ...");
684     if (!rolledLogDeleter.has_candidates()) {
685       Note("Cannot clear space because there are no recognized Traffic Server rolled logs for auto deletion.");
686     } else {
687       Debug("logspace", "Considering %zu delete candidates ...", rolledLogDeleter.get_candidate_count());
688     }
689 
690     while (rolledLogDeleter.has_candidates()) {
691       if (space_to_write(headroom + log_buffer_size)) {
692         Debug("logspace", "low water mark reached; stop deleting");
693         break;
694       }
695 
696       auto victim = rolledLogDeleter.take_next_candidate_to_delete();
697       // Check if any candidate exists
698       if (!victim) {
699         // This shouldn't be triggered unless min_count are configured wrong or extra non-log files occupy the directory
700         Debug("logspace", "No more victims. Check your rolling_min_count settings and logging directory.");
701       } else {
702         Debug("logspace", "auto-deleting %s", victim->rolled_log_path.c_str());
703 
704         if (unlink(victim->rolled_log_path.c_str()) < 0) {
705           Note("Traffic Server was unable to auto-delete rolled "
706                "logfile %s: %s.",
707                victim->rolled_log_path.c_str(), strerror(errno));
708         } else {
709           Debug("logspace",
710                 "The rolled logfile, %s, was auto-deleted; "
711                 "%" PRId64 " bytes were reclaimed.",
712                 victim->rolled_log_path.c_str(), victim->size);
713 
714           // Update after successful unlink;
715           m_space_used -= victim->size;
716           m_partition_space_left += victim->size;
717         }
718       }
719     }
720   }
721 
722   // The set of files in the logs dir may change between iterations to check
723   // for logs to delete. To deal with this, we simply clear our internal
724   // candidates metadata and regenerate it on each iteration.
725   rolledLogDeleter.clear_candidates();
726 
727   //
728   // Now that we've updated the m_space_used value, see if we need to
729   // issue any alarms or warnings about space
730   //
731 
732   if (!space_to_write(headroom)) {
733     if (!logging_space_exhausted) {
734       Note("Logging space exhausted, any logs writing to local disk will be dropped!");
735     }
736 
737     logging_space_exhausted = true;
738     //
739     // Despite our best efforts, we still can't write to the disk.
740     // Find out why and set/clear warnings.
741     //
742     // First, are we out of space based on configuration?
743     //
744     if (m_space_used >= max_space) {
745       if (!m_disk_full) {
746         m_disk_full = true;
747         LogUtils::manager_alarm(LogUtils::LOG_ALARM_ERROR, DISK_IS_CONFIG_FULL_MESSAGE);
748         Warning(DISK_IS_CONFIG_FULL_MESSAGE);
749       }
750     }
751     //
752     // How about out of actual space on the partition?
753     //
754     else if (m_partition_space_left <= 0) {
755       if (!m_partition_full) {
756         m_partition_full = true;
757         LogUtils::manager_alarm(LogUtils::LOG_ALARM_ERROR, DISK_IS_ACTUAL_FULL_MESSAGE);
758         Warning(DISK_IS_ACTUAL_FULL_MESSAGE);
759       }
760     }
761     //
762     // How about being within the headroom limit?
763     //
764     else if (m_space_used + headroom >= max_space) {
765       if (!m_disk_low) {
766         m_disk_low = true;
767         LogUtils::manager_alarm(LogUtils::LOG_ALARM_ERROR, DISK_IS_CONFIG_LOW_MESSAGE);
768         Warning(DISK_IS_CONFIG_LOW_MESSAGE);
769       }
770     } else {
771       if (!m_partition_low) {
772         m_partition_low = true;
773         LogUtils::manager_alarm(LogUtils::LOG_ALARM_ERROR, DISK_IS_ACTUAL_LOW_MESSAGE);
774         Warning(DISK_IS_ACTUAL_LOW_MESSAGE);
775       }
776     }
777   } else {
778     //
779     // We have enough space to log again; clear any previous messages
780     //
781     if (logging_space_exhausted) {
782       Note("Logging space is no longer exhausted.");
783     }
784 
785     logging_space_exhausted = false;
786     if (m_disk_full || m_partition_full) {
787       Note("Logging disk is no longer full; access logging to local log directory resumed.");
788       m_disk_full      = false;
789       m_partition_full = false;
790     }
791     if (m_disk_low || m_partition_low) {
792       Note("Logging disk is no longer low; access logging to local log directory resumed.");
793       m_disk_low      = false;
794       m_partition_low = false;
795     }
796   }
797 }
798 
799 bool
evaluate_config()800 LogConfig::evaluate_config()
801 {
802   ats_scoped_str path(RecConfigReadConfigPath("proxy.config.log.config.filename", ts::filename::LOGGING));
803   struct stat sbuf;
804   if (stat(path.get(), &sbuf) == -1 && errno == ENOENT) {
805     Warning("logging configuration '%s' doesn't exist", path.get());
806     return false;
807   }
808 
809   Note("%s loading ...", path.get());
810   YamlLogConfig y(this);
811 
812   bool zret = y.parse(path.get());
813   if (zret) {
814     Note("%s finished loading", path.get());
815   } else {
816     Note("%s failed to load", path.get());
817   }
818 
819   return zret;
820 }
821