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