You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@trafficserver.apache.org by yu...@apache.org on 2013/08/09 08:35:24 UTC
[3/3] git commit: TS-2063: LogFile::write_ascii_logbuffer3() can
silently drop log entries
TS-2063: LogFile::write_ascii_logbuffer3() can silently drop log entries
1) Avoid silently dropping log entries in write_ascii_logbuffer3().
2) Remove overspill logic, and try to write log to disk as much as possible.
3) Simplify the code by removing unecessary *overspill* variables.
Signed-off-by: Yunkai Zhang <qi...@taobao.com>
Project: http://git-wip-us.apache.org/repos/asf/trafficserver/repo
Commit: http://git-wip-us.apache.org/repos/asf/trafficserver/commit/5b002b11
Tree: http://git-wip-us.apache.org/repos/asf/trafficserver/tree/5b002b11
Diff: http://git-wip-us.apache.org/repos/asf/trafficserver/diff/5b002b11
Branch: refs/heads/master
Commit: 5b002b11ccecf31f1b66f9203f52f207034f605d
Parents: 3c49b11
Author: Yunkai Zhang <qi...@taobao.com>
Authored: Wed Aug 7 15:18:13 2013 +0800
Committer: Yunkai Zhang <qi...@taobao.com>
Committed: Fri Aug 9 14:30:12 2013 +0800
----------------------------------------------------------------------
mgmt/RecordsConfig.cc | 2 -
proxy/logging/LogConfig.cc | 6 --
proxy/logging/LogConfig.h | 1 -
proxy/logging/LogFile.cc | 124 ++++++++++++++++------------------------
proxy/logging/LogFile.h | 14 +----
proxy/logging/LogObject.cc | 3 +-
6 files changed, 51 insertions(+), 99 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/5b002b11/mgmt/RecordsConfig.cc
----------------------------------------------------------------------
diff --git a/mgmt/RecordsConfig.cc b/mgmt/RecordsConfig.cc
index 23e3c82..cfc2267 100644
--- a/mgmt/RecordsConfig.cc
+++ b/mgmt/RecordsConfig.cc
@@ -1167,8 +1167,6 @@ RecordElement RecordsConfig[] = {
,
{RECT_CONFIG, "proxy.config.log.max_line_size", RECD_INT, "9216", RECU_DYNAMIC, RR_NULL, RECC_NULL, NULL, RECA_NULL}
,
- {RECT_CONFIG, "proxy.config.log.overspill_report_count", RECD_INT, "500", RECU_DYNAMIC, RR_NULL, RECC_NULL, NULL, RECA_NULL}
- ,
{RECT_CONFIG, "proxy.config.log.xuid_logging_enabled", RECD_INT, "1", RECU_DYNAMIC, RR_NULL, RECC_NULL, NULL, RECA_NULL}
,
// Begin HCL Modifications.
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/5b002b11/proxy/logging/LogConfig.cc
----------------------------------------------------------------------
diff --git a/proxy/logging/LogConfig.cc b/proxy/logging/LogConfig.cc
index abd89f9..62875a8 100644
--- a/proxy/logging/LogConfig.cc
+++ b/proxy/logging/LogConfig.cc
@@ -183,7 +183,6 @@ LogConfig::setup_default_values()
ascii_buffer_size = 4 * 9216;
max_line_size = 9216; // size of pipe buffer for SunOS 5.6
- overspill_report_count = 500;
}
void *
@@ -488,11 +487,6 @@ LogConfig::read_configuration_variables()
max_line_size = val;
}
- val = (int) LOG_ConfigReadInteger("proxy.config.log.overspill_report_count");
- if (val > 0) {
- overspill_report_count = val;
- }
-
/* The following variables are initialized after reading the */
/* variable values from records.config */
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/5b002b11/proxy/logging/LogConfig.h
----------------------------------------------------------------------
diff --git a/proxy/logging/LogConfig.h b/proxy/logging/LogConfig.h
index 11f5b01..654b276 100644
--- a/proxy/logging/LogConfig.h
+++ b/proxy/logging/LogConfig.h
@@ -241,7 +241,6 @@ public:
int ascii_buffer_size;
int max_line_size;
- int overspill_report_count;
char *hostname;
char *logfile_dir;
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/5b002b11/proxy/logging/LogFile.cc
----------------------------------------------------------------------
diff --git a/proxy/logging/LogFile.cc b/proxy/logging/LogFile.cc
index e7b9593..430b75a 100644
--- a/proxy/logging/LogFile.cc
+++ b/proxy/logging/LogFile.cc
@@ -86,20 +86,16 @@ static const int FILESIZE_SAFE_THRESHOLD_FACTOR = 10;
-------------------------------------------------------------------------*/
LogFile::LogFile(const char *name, const char *header, LogFileFormat format,
- uint64_t signature, size_t ascii_buffer_size, size_t max_line_size, size_t overspill_report_count)
+ 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_max_line_size(max_line_size),
- m_overspill_report_count(overspill_report_count)
+ m_max_line_size(max_line_size)
{
delete m_meta_info;
m_meta_info = NULL;
- m_overspill_bytes = 0;
- m_overspill_written = 0;
- m_attempts_to_write_overspill = 0;
m_fd = -1;
m_start_time = 0L;
m_end_time = 0L;
@@ -107,7 +103,6 @@ LogFile::LogFile(const char *name, const char *header, LogFileFormat format,
m_size_bytes = 0;
m_ascii_buffer_size = (ascii_buffer_size < max_line_size ? max_line_size : ascii_buffer_size);
m_ascii_buffer = NEW(new char[m_ascii_buffer_size]);
- m_overspill_buffer = NEW(new char[m_max_line_size]);
Debug("log-file", "exiting LogFile constructor, m_name=%s, this=%p", m_name, this);
}
@@ -126,10 +121,6 @@ LogFile::LogFile (const LogFile& copy)
m_meta_info (NULL),
m_ascii_buffer_size (copy.m_ascii_buffer_size),
m_max_line_size (copy.m_max_line_size),
- m_overspill_bytes (0),
- m_overspill_written (0),
- m_attempts_to_write_overspill (0),
- m_overspill_report_count (copy.m_overspill_report_count),
m_fd (-1),
m_start_time (0L),
m_end_time (0L),
@@ -137,7 +128,6 @@ LogFile::LogFile (const LogFile& copy)
{
ink_assert(m_ascii_buffer_size >= m_max_line_size);
m_ascii_buffer = NEW (new char[m_ascii_buffer_size]);
- m_overspill_buffer = NEW (new char[m_max_line_size]);
Debug("log-file", "exiting LogFile copy constructor, m_name=%s, this=%p",
m_name, this);
@@ -156,8 +146,6 @@ LogFile::~LogFile()
delete m_meta_info;
delete[]m_ascii_buffer;
m_ascii_buffer = 0;
- delete[]m_overspill_buffer;
- m_overspill_buffer = 0;
Debug("log-file", "exiting LogFile destructor, this=%p", this);
}
@@ -661,81 +649,67 @@ LogFile::write_ascii_logbuffer3(LogBufferHeader * buffer_header, char *alt_forma
while ((entry_header = iter.next())) {
fmt_buf_bytes = 0;
+ ink_release_assert(m_ascii_buffer_size >= m_max_line_size);
+
// fill the buffer with as many records as possible
//
do {
- if (m_ascii_buffer_size - fmt_buf_bytes >= m_max_line_size) {
- int bytes = LogBuffer::to_ascii(entry_header, format_type,
- &m_ascii_buffer[fmt_buf_bytes],
- m_max_line_size - 1,
- fieldlist_str, printf_str,
- buffer_header->version,
- alt_format);
-
- if (bytes > 0) {
- fmt_buf_bytes += bytes;
- m_ascii_buffer[fmt_buf_bytes] = '\n';
- ++fmt_buf_bytes;
- }
- // if writing to a pipe, fill the buffer with a single
- // record to avoid as much as possible overflowing the
- // pipe buffer
- //
- if (m_file_format == ASCII_PIPE)
- break;
+ if (entry_header->entry_len >= m_max_line_size) {
+ Warning("Log is too long(%"PRIu32"), it would be truncated. max_len:%zu",
+ entry_header->entry_len, m_max_line_size);
}
- } while ((entry_header = iter.next()));
- ssize_t bytes_written;
-
- // try to write any data that may not have been written in a
- // previous attempt
- //
- if (m_overspill_bytes) {
- bytes_written = 0;
- if (!Log::config->logging_space_exhausted) {
- bytes_written =::write(m_fd, &m_overspill_buffer[m_overspill_written], m_overspill_bytes);
- }
- if (bytes_written < 0) {
- Error("An error was encountered in writing to %s: %s.", ((m_name) ? m_name : "logfile"), strerror(errno));
+ int bytes = LogBuffer::to_ascii(entry_header, format_type,
+ &m_ascii_buffer[fmt_buf_bytes],
+ m_max_line_size - 1,
+ fieldlist_str, printf_str,
+ buffer_header->version,
+ alt_format);
+
+ if (bytes > 0) {
+ fmt_buf_bytes += bytes;
+ m_ascii_buffer[fmt_buf_bytes] = '\n';
+ ++fmt_buf_bytes;
} else {
- m_overspill_bytes -= bytes_written;
- m_overspill_written += bytes_written;
+ Error("Failed to convert LogBuffer to ascii, have dropped (%"PRIu32") bytes.",
+ entry_header->entry_len);
}
+ // if writing to a pipe, fill the buffer with a single
+ // record to avoid as much as possible overflowing the
+ // pipe buffer
+ //
+ if (m_file_format == ASCII_PIPE)
+ break;
- if (m_overspill_bytes) {
- ++m_attempts_to_write_overspill;
- if (m_overspill_report_count && (m_attempts_to_write_overspill % m_overspill_report_count == 0)) {
- Warning("Have dropped %zu records so far because buffer "
- "for %s is full", m_attempts_to_write_overspill, m_name);
- }
- } else if (m_attempts_to_write_overspill) {
- Warning("Dropped %zu records because buffer for %s was full", m_attempts_to_write_overspill, m_name);
- m_attempts_to_write_overspill = 0;
- }
- }
- // write the buffer out to the file or pipe
+ if (m_ascii_buffer_size - fmt_buf_bytes < m_max_line_size)
+ break;
+ } while ((entry_header = iter.next()));
+
+ int bytes_written = 0;
+
+ // try to write *all* the buffer out to the file or pipe
//
- if (fmt_buf_bytes && !m_overspill_bytes) {
- bytes_written = 0;
- if (!Log::config->logging_space_exhausted) {
- bytes_written =::write(m_fd, m_ascii_buffer, fmt_buf_bytes);
+ while (bytes_written < fmt_buf_bytes) {
+ if (Log::config->logging_space_exhausted) {
+ Warning("logging space exhausted, have dropped (%d) bytes.",
+ (fmt_buf_bytes - bytes_written));
+ break;
}
- if (bytes_written < 0) {
- Error("An error was encountered in writing to %s: %s.", ((m_name) ? m_name : "logfile"), strerror(errno));
- } else {
- if (bytes_written < fmt_buf_bytes) {
- m_overspill_bytes = fmt_buf_bytes - bytes_written;
- if (m_overspill_bytes > m_max_line_size)
- m_overspill_bytes = m_max_line_size;
- memcpy(m_overspill_buffer, &m_ascii_buffer[bytes_written], m_overspill_bytes);
- m_overspill_written = 0;
- }
- total_bytes += bytes_written;
+ int cnt = ::write(m_fd, &m_ascii_buffer[bytes_written],
+ (fmt_buf_bytes - bytes_written));
+ if (cnt < 0) {
+ Error("An error was encountered in writing to %s: %s.",
+ ((m_name) ? m_name : "logfile"), strerror(errno));
+ break;
}
+
+ bytes_written += cnt;
}
+
+ total_bytes += bytes_written;
}
+
return total_bytes;
}
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/5b002b11/proxy/logging/LogFile.h
----------------------------------------------------------------------
diff --git a/proxy/logging/LogFile.h b/proxy/logging/LogFile.h
index 09c6660..8d3a4a8 100644
--- a/proxy/logging/LogFile.h
+++ b/proxy/logging/LogFile.h
@@ -127,8 +127,7 @@ class LogFile:public LogBufferSink
{
public:
LogFile(const char *name, const char *header, LogFileFormat format, uint64_t signature,
- size_t ascii_buffer_size = 4 * 9216, size_t max_line_size = 9216,
- size_t overspill_report_count = 1000);
+ size_t ascii_buffer_size = 4 * 9216, size_t max_line_size = 9216);
LogFile(const LogFile &);
~LogFile();
@@ -184,17 +183,6 @@ private:
char *m_ascii_buffer; // buffer for ascii output
size_t m_ascii_buffer_size; // size of ascii buffer
size_t m_max_line_size; // size of longest log line (record)
- // (including newline)
- char *m_overspill_buffer; // buffer for data that did not fit
- // the pipe buffer
- size_t m_overspill_bytes; // bytes in the overspill buffer
- size_t m_overspill_written; // bytes in overspill that have been
- // transferred to pipe buffer
- size_t m_attempts_to_write_overspill; // times transfer from overspill to
- // pipe buffer has been attempted
- size_t m_overspill_report_count; // number of attempts at which
- // overspill report is written to
- // diags log
int m_fd;
long m_start_time;
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/5b002b11/proxy/logging/LogObject.cc
----------------------------------------------------------------------
diff --git a/proxy/logging/LogObject.cc b/proxy/logging/LogObject.cc
index 6af216e..c4bcd5d 100644
--- a/proxy/logging/LogObject.cc
+++ b/proxy/logging/LogObject.cc
@@ -113,8 +113,7 @@ LogObject::LogObject(LogFormat *format, const char *log_dir,
m_logFile = NEW(new LogFile (m_filename, header, file_format,
m_signature,
Log::config->ascii_buffer_size,
- Log::config->max_line_size,
- Log::config->overspill_report_count));
+ Log::config->max_line_size));
LogBuffer *b = NEW (new LogBuffer (this, Log::config->log_buffer_size));
ink_assert(b);