Cord Beermann <cord@cc.fh-lippe.de>
Daniel O'Callaghan <danny@miriworld.its.unimelb.EDU.AU>
David Luyer <luyer@ucs.uwa.edu.au>
+ Dhaval Varia
Diego Woitasen <diegows@xtech.com.ar>
Dmitry Kurochkin
Don Hopkins <dhopkins@DonHopkins.com>
multicast.h \
multicast.cc \
mem_node.cc \
+ MemBlob.cc \
MemBuf.cc \
MemObject.cc \
mime.h \
Mem.h \
mem.cc \
mem_node.cc \
+ MemBlob.cc \
MemBuf.cc \
MemObject.cc \
mime.h \
internal.cc \
SquidList.h \
SquidList.cc \
+ MemBlob.cc \
MemBuf.cc \
MemObject.cc \
Mem.h \
ipcache.cc \
SquidList.h \
SquidList.cc \
+ MemBlob.cc \
MemBuf.cc \
MemObject.cc \
Mem.h \
multicast.h \
multicast.cc \
mem_node.cc \
+ MemBlob.cc \
MemBuf.cc \
MemObject.cc \
mime.h \
Mem.h \
mem.cc \
mem_node.cc \
+ MemBlob.cc \
MemBuf.cc \
MemObject.cc \
mime.h \
/* next expect a list of ACL names, possibly preceeded
* by '!' for negation */
- while ((t = strtok(NULL, w_space))) {
+ while ((t = parser.strtokFile())) {
ACLList *L = new ACLList;
if (*t == '!') {
if (log->type == Log::Format::CLF_NONE)
continue;
- log->logfile = logfileOpen(log->filename, MAX_URL << 1, 1);
+ log->logfile = logfileOpen(log->filename, log->bufferSize, log->fatal);
IcapLogfileStatus = LOG_ENABLE;
}
static int check_null_access_log(CustomLog *customlog_definitions);
static void dump_access_log(StoreEntry * entry, const char *name, CustomLog * definitions);
static void free_access_log(CustomLog ** definitions);
+static bool setLogformat(CustomLog *cl, const char *name, const bool dieWhenMissing);
static void update_maxobjsize(void);
static void configDoConfigure(void);
}
#endif
-#if USE_SSL
/**
* Parse bytes from a string.
* Similar to the parseBytesLine function but parses the string value instead of
if (static_cast<double>(*bptr) * 2 != (m * d / u) * 2)
self_destruct();
}
-#endif
static size_t
parseBytesUnits(const char *unit)
#include "AccessLogEntry.h"
+/**
+ * We support several access_log configuration styles:
+ *
+ * #1: Deprecated ancient style without an explicit logging module:
+ * access_log /var/log/access.log
+ *
+ * #2: The "none" logging module (i.e., no logging [of matching transactions]):
+ * access_log none [acl ...]
+ *
+ * #3: Configurable logging module without named options:
+ * Logformat or the first ACL name, whichever comes first, may not contain '='.
+ * If no explicit logformat name is given, the first ACL name, if any,
+ * should not be an existing logformat name or it will be treated as such.
+ * access_log module:place [logformat_name] [acl ...]
+ *
+ * #4: Configurable logging module with name=value options such as logformat=x:
+ * The first ACL name may not contain '='.
+ * access_log module:place [option ...] [acl ...]
+ *
+ */
static void
parse_access_log(CustomLog ** logs)
{
- const char *filename, *logdef_name;
-
CustomLog *cl = (CustomLog *)xcalloc(1, sizeof(*cl));
- if ((filename = strtok(NULL, w_space)) == NULL) {
+ // default buffer size and fatal settings
+ cl->bufferSize = 8*MAX_URL;
+ cl->fatal = true;
+
+ /* determine configuration style */
+
+ const char *filename = strtok(NULL, w_space);
+ if (!filename) {
self_destruct();
return;
}
return;
}
- if ((logdef_name = strtok(NULL, w_space)) == NULL)
- logdef_name = "squid";
+ cl->filename = xstrdup(filename);
+ cl->type = Log::Format::CLF_UNKNOWN;
+
+ const char *token = ConfigParser::strtokFile();
+ if (!token) { // style #1
+ // no options to deal with
+ } else if (!strchr(token, '=')) { // style #3
+ // if logformat name is not recognized,
+ // put back the token; it must be an ACL name
+ if (!setLogformat(cl, token, false))
+ ConfigParser::strtokFileUndo();
+ } else { // style #4
+ do {
+ if (strncasecmp(token, "on-error=", 9) == 0) {
+ if (strncasecmp(token+9, "die", 3) == 0) {
+ cl->fatal = true;
+ } else if (strncasecmp(token+9, "drop", 4) == 0) {
+ cl->fatal = false;
+ } else {
+ debugs(3, DBG_CRITICAL, "Unknown value for on-error '" <<
+ token << "' expected 'drop' or 'die'");
+ self_destruct();
+ }
+ } else if (strncasecmp(token, "buffer-size=", 12) == 0) {
+ parseBytesOptionValue(&cl->bufferSize, B_BYTES_STR, token+12);
+ } else if (strncasecmp(token, "logformat=", 10) == 0) {
+ setLogformat(cl, token+10, true);
+ } else if (!strchr(token, '=')) {
+ // put back the token; it must be an ACL name
+ ConfigParser::strtokFileUndo();
+ break; // done with name=value options, now to ACLs
+ } else {
+ debugs(3, DBG_CRITICAL, "Unknown access_log option " << token);
+ self_destruct();
+ }
+ } while ((token = ConfigParser::strtokFile()) != NULL);
+ }
- debugs(3, 9, "Log definition name '" << logdef_name << "' file '" << filename << "'");
+ // set format if it has not been specified explicitly
+ if (cl->type == Log::Format::CLF_UNKNOWN)
+ setLogformat(cl, "squid", true);
- cl->filename = xstrdup(filename);
+ aclParseAclList(LegacyParser, &cl->aclList);
+
+ while (*logs)
+ logs = &(*logs)->next;
+
+ *logs = cl;
+}
+
+/// sets CustomLog::type and, if needed, CustomLog::lf
+/// returns false iff there is no named log format
+static bool
+setLogformat(CustomLog *cl, const char *logdef_name, const bool dieWhenMissing)
+{
+ assert(cl);
+ assert(logdef_name);
+
+ debugs(3, 9, "possible " << cl->filename << " logformat: " << logdef_name);
+
+ if (cl->type != Log::Format::CLF_UNKNOWN) {
+ debugs(3, DBG_CRITICAL, "Second logformat name in one access_log: " <<
+ logdef_name << " " << cl->type << " ? " << Log::Format::CLF_NONE);
+ self_destruct();
+ return false;
+ }
/* look for the definition pointer corresponding to this name */
Format::Format *lf = Log::TheConfig.logformats;
cl->type = Log::Format::CLF_USERAGENT;
} else if (strcmp(logdef_name, "referrer") == 0) {
cl->type = Log::Format::CLF_REFERER;
- } else {
+ } else if (dieWhenMissing) {
debugs(3, DBG_CRITICAL, "Log format '" << logdef_name << "' is not defined");
self_destruct();
- return;
+ return false;
+ } else {
+ return false;
}
- aclParseAclList(LegacyParser, &cl->aclList);
-
- while (*logs)
- logs = &(*logs)->next;
-
- *logs = cl;
+ return true;
}
static int
LOC: Config.Log.accesslogs
DEFAULT_IF_NONE: daemon:@DEFAULT_ACCESS_LOG@ squid
DOC_START
- These files log client request activities. Has a line every HTTP or
- ICP request. The format is:
+ Configures whether and how Squid logs HTTP and ICP transactions.
+ If access logging is enabled, a single line is logged for every
+ matching HTTP or ICP request. The recommended directive formats are:
+
+ access_log <module>:<place> [option ...] [acl acl ...]
+ access_log none [acl acl ...]
+
+ The following directive format is accepted but may be deprecated:
access_log <module>:<place> [<logformat name> [acl acl ...]]
- access_log none [acl acl ...]]
+
+ In most cases, the first ACL name must not contain the '=' character
+ and should not be equal to an existing logformat name. You can always
+ start with an 'all' ACL to work around those restrictions.
Will log to the specified module:place using the specified format (which
must be defined in a logformat directive) those entries which match
ALL the acl's specified (which must be defined in acl clauses).
If no acl is specified, all requests will be logged to this destination.
+ ===== Available options for the recommended directive format =====
+
+ logformat=name Names log line format (either built-in or
+ defined by a logformat directive). Defaults
+ to 'squid'.
+
+ buffer-size=64KB Defines approximate buffering limit for log
+ records (see buffered_logs). Squid should not
+ keep more than the specified size and, hence,
+ should flush records before the buffer becomes
+ full to avoid overflows under normal
+ conditions (the exact flushing algorithm is
+ module-dependent though). The on-error option
+ controls overflow handling.
+
+ on-error=die|drop Defines action on unrecoverable errors. The
+ 'drop' action ignores (i.e., does not log)
+ affected log records. The default 'die' action
+ kills the affected worker. The drop action
+ support has not been tested for modules other
+ than tcp.
+
===== Modules Currently available =====
none Do not log any requests matching these ACL.
Place Format: //host:port
tcp To send each log line as text data to a TCP receiver.
+ Lines may be accumulated before sending (see buffered_logs).
Place: The destination host name or IP and port.
Place Format: //host:port
records if it cannot write/send them immediately due to pending I/Os
(e.g., the I/O writing the previous log record) or connectivity loss.
- Currently honored by 'daemon' access_log module only.
+ Currently honored by 'daemon' and 'tcp' access_log modules only.
DOC_END
NAME: netdb_filename
Logfile *logfile;
CustomLog *next;
Log::Format::log_type type;
+ /// how much to buffer before dropping or dying (access_log buffer-size)
+ size_t bufferSize;
+ /// whether unrecoverable errors (e.g., dropping a log record) kill worker
+ bool fatal;
};
#endif /* SQUID_CUSTOMLOG_H_ */
#include "log/ModStdio.h"
#include "log/ModSyslog.h"
#include "log/ModUdp.h"
-#include "log/ModTcp.h"
+#include "log/TcpLogger.h"
CBDATA_TYPE(Logfile);
ret = logfile_mod_daemon_open(lf, patharg, bufsz, fatal_flag);
} else if (strncmp(path, "tcp:", 4) == 0) {
patharg = path + 4;
- ret = logfile_mod_tcp_open(lf, patharg, bufsz, fatal_flag);
+ ret = Log::TcpLogger::Open(lf, patharg, bufsz, fatal_flag);
} else if (strncmp(path, "udp:", 4) == 0) {
patharg = path + 4;
ret = logfile_mod_udp_open(lf, patharg, bufsz, fatal_flag);
ret = logfile_mod_syslog_open(lf, patharg, bufsz, fatal_flag);
#endif
} else {
- debugs(50, DBG_IMPORTANT, "WARNING: log parameters now start with a module name. Use 'stdio:" << patharg << "'");
+ debugs(50, DBG_IMPORTANT, "WARNING: log name now starts with a module name. Use 'stdio:" << patharg << "'");
snprintf(lf->path, MAXPATHLEN, "stdio:%s", patharg);
ret = logfile_mod_stdio_open(lf, patharg, bufsz, fatal_flag);
}
ModStdio.h \
ModSyslog.cc \
ModSyslog.h \
- ModTcp.cc \
- ModTcp.h \
ModUdp.cc \
ModUdp.h \
CustomLog.h \
- CustomLog.cc
+ CustomLog.cc \
+ TcpLogger.cc \
+ TcpLogger.h
+++ /dev/null
-/*
- * DEBUG: section 50 Log file handling
- * AUTHOR: Dhaval Varia
- * Developed based on ModUdp.* by Adrian Chadd
- *
- * SQUID Web Proxy Cache http://www.squid-cache.org/
- * ----------------------------------------------------------
- *
- * Squid is the result of efforts by numerous individuals from
- * the Internet community; see the CONTRIBUTORS file for full
- * details. Many organizations have provided support for Squid's
- * development; see the SPONSORS file for full details. Squid is
- * Copyrighted (C) 2001 by the Regents of the University of
- * California; see the COPYRIGHT file for full details. Squid
- * incorporates software developed and/or copyrighted by other
- * sources; see the CREDITS file for full details.
- *
- * This program is free software; you can redistribute it and/or modify
- * it under the terms of the GNU General Public License as published by
- * the Free Software Foundation; either version 2 of the License, or
- * (at your option) any later version.
- *
- * This program is distributed in the hope that it will be useful,
- * but WITHOUT ANY WARRANTY; without even the implied warranty of
- * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
- * GNU General Public License for more details.
- *
- * You should have received a copy of the GNU General Public License
- * along with this program; if not, write to the Free Software
- * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111, USA.
- *
- */
-
-#include "squid.h"
-#include "comm.h"
-#include "comm/Connection.h"
-#include "disk.h"
-#include "fd.h"
-#include "log/File.h"
-#include "log/ModTcp.h"
-#include "Parsing.h"
-#include "SquidConfig.h"
-
-#if HAVE_ERRNO_H
-#include <errno.h>
-#endif
-/*
- * This logfile TCP module is mostly inspired by a patch by Tim Starling
- * from Wikimedia.
- *
- * It doesn't do any TCP buffering - it'd be quite a bit of work for
- * something which the kernel could be doing for you!
- */
-
-typedef struct {
- int fd;
- char *buf;
- size_t bufsz;
- int offset;
-} l_tcp_t;
-
-static void
-logfile_mod_tcp_write(Logfile * lf, const char *buf, size_t len)
-{
- l_tcp_t *ll = (l_tcp_t *) lf->data;
- ssize_t s;
- s = write(ll->fd, (char const *) buf, len);
-
- fd_bytes(ll->fd, s, FD_WRITE);
-#if 0
- if (s < 0) {
- debugs(1, DBG_IMPORTANT, "logfile (tcp): got errno (" << errno << "):" << xstrerror());
- }
- if (s != len) {
- debugs(1, DBG_IMPORTANT, "logfile (tcp): len=" << len << ", wrote=" << s);
- }
-#endif
-
- /* We don't worry about network errors for now */
-}
-
-static void
-logfile_mod_tcp_flush(Logfile * lf)
-{
- l_tcp_t *ll = (l_tcp_t *) lf->data;
- if (0 == ll->offset)
- return;
- logfile_mod_tcp_write(lf, ll->buf, (size_t) ll->offset);
- ll->offset = 0;
-}
-
-static void
-logfile_mod_tcp_writeline(Logfile * lf, const char *buf, size_t len)
-{
- l_tcp_t *ll = (l_tcp_t *) lf->data;
-
- if (0 == ll->bufsz) {
- /* buffering disabled */
- logfile_mod_tcp_write(lf, buf, len);
- return;
- }
- if (ll->offset > 0 && (ll->offset + len + 4) > ll->bufsz)
- logfile_mod_tcp_flush(lf);
-
- if (len > ll->bufsz) {
- /* too big to fit in buffer */
- logfile_mod_tcp_write(lf, buf, len);
- return;
- }
- /* buffer it */
- memcpy(ll->buf + ll->offset, buf, len);
-
- ll->offset += len;
-
- assert(ll->offset >= 0);
-
- assert((size_t) ll->offset <= ll->bufsz);
-}
-
-static void
-logfile_mod_tcp_linestart(Logfile * lf)
-{
-}
-
-static void
-logfile_mod_tcp_lineend(Logfile * lf)
-{
- logfile_mod_tcp_flush(lf);
-}
-
-static void
-logfile_mod_tcp_rotate(Logfile * lf)
-{
- return;
-}
-
-static void
-logfile_mod_tcp_close(Logfile * lf)
-{
- l_tcp_t *ll = (l_tcp_t *) lf->data;
- lf->f_flush(lf);
-
- if (ll->fd >= 0)
- file_close(ll->fd);
-
- if (ll->buf)
- xfree(ll->buf);
-
- xfree(lf->data);
- lf->data = NULL;
-}
-
-/*
- * This code expects the path to be //host:port
- */
-int
-logfile_mod_tcp_open(Logfile * lf, const char *path, size_t bufsz, int fatal_flag)
-{
- debugs(5, 3, "Tcp Open called");
- Ip::Address addr;
-
- char *strAddr;
-
- lf->f_close = logfile_mod_tcp_close;
- lf->f_linewrite = logfile_mod_tcp_writeline;
- lf->f_linestart = logfile_mod_tcp_linestart;
- lf->f_lineend = logfile_mod_tcp_lineend;
- lf->f_flush = logfile_mod_tcp_flush;
- lf->f_rotate = logfile_mod_tcp_rotate;
-
- l_tcp_t *ll = static_cast<l_tcp_t*>(xcalloc(1, sizeof(*ll)));
- lf->data = ll;
-
- if (strncmp(path, "//", 2) == 0) {
- path += 2;
- }
- strAddr = xstrdup(path);
-
- if (!GetHostWithPort(strAddr, &addr)) {
- if (lf->flags.fatal) {
- fatalf("Invalid TCP logging address '%s'\n", lf->path);
- } else {
- debugs(50, DBG_IMPORTANT, "Invalid TCP logging address '" << lf->path << "'");
- safe_free(strAddr);
- return FALSE;
- }
- }
-
- safe_free(strAddr);
-
- Ip::Address any_addr;
- any_addr.SetAnyAddr();
-
- // require the sending TCP port to be of the right family for the destination address.
- if (addr.IsIPv4())
- any_addr.SetIPv4();
-
- ll->fd = comm_open(SOCK_STREAM, IPPROTO_TCP, any_addr, COMM_NONBLOCKING, "TCP log socket");
- if (ll->fd < 0) {
- if (lf->flags.fatal) {
- fatalf("Unable to open TCP socket for logging\n");
- } else {
- debugs(50, DBG_IMPORTANT, "Unable to open TCP socket for logging");
- return FALSE;
- }
- } else if (!comm_connect_addr(ll->fd, &addr)) {
- if (lf->flags.fatal) {
- fatalf("Unable to connect to %s for TCP log: %s\n", lf->path, xstrerror());
- } else {
- debugs(50, DBG_IMPORTANT, "Unable to connect to " << lf->path << " for TCP log: " << xstrerror());
- return FALSE;
- }
- }
- if (ll->fd == -1) {
- if (ENOENT == errno && fatal_flag) {
- fatalf("Cannot open '%s' because\n"
- "\tthe parent directory does not exist.\n"
- "\tPlease create the directory.\n", path);
- } else if (EACCES == errno && fatal_flag) {
- fatalf("Cannot open '%s' for writing.\n"
- "\tThe parent directory must be writeable by the\n"
- "\tuser '%s', which is the cache_effective_user\n"
- "\tset in squid.conf.", path, Config.effectiveUser);
- } else {
- debugs(50, DBG_IMPORTANT, "logfileOpen (TCP): " << lf->path << ": " << xstrerror());
- return 0;
- }
- }
-
- bufsz = 65536;
- if (bufsz > 0) {
- ll->buf = static_cast<char*>(xmalloc(bufsz));
- ll->bufsz = bufsz;
- }
-
- return 1;
-}
+++ /dev/null
-/*
- * DEBUG: section 50 Log file handling
- * AUTHOR: Dhaval Varia
- * Developed based on ModUdp.* by Adrian Chadd
- *
- * SQUID Web Proxy Cache http://www.squid-cache.org/
- * ----------------------------------------------------------
- *
- * Squid is the result of efforts by numerous individuals from
- * the Internet community; see the CONTRIBUTORS file for full
- * details. Many organizations have provided support for Squid's
- * development; see the SPONSORS file for full details. Squid is
- * Copyrighted (C) 2001 by the Regents of the University of
- * California; see the COPYRIGHT file for full details. Squid
- * incorporates software developed and/or copyrighted by other
- * sources; see the CREDITS file for full details.
- *
- * This program is free software; you can redistribute it and/or modify
- * it under the terms of the GNU General Public License as published by
- * the Free Software Foundation; either version 2 of the License, or
- * (at your option) any later version.
- *
- * This program is distributed in the hope that it will be useful,
- * but WITHOUT ANY WARRANTY; without even the implied warranty of
- * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
- * GNU General Public License for more details.
- *
- * You should have received a copy of the GNU General Public License
- * along with this program; if not, write to the Free Software
- * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111, USA.
- *
- */
-#ifndef _SQUID_SRC_LOG_MODTCP_H
-#define _SQUID_SRC_LOG_MODTCP_H
-
-class Logfile;
-
-int logfile_mod_tcp_open(Logfile * lf, const char *path, size_t bufsz, int fatal_flag);
-
-#endif /* _SQUID_SRC_LOG_MODTCP_H */
--- /dev/null
+#include "squid.h"
+#include "comm.h"
+#include "comm/ConnOpener.h"
+#include "comm/Connection.h"
+#include "comm/Loops.h"
+#include "comm/Write.h"
+#include "fde.h"
+#include "globals.h" // for shutting_down
+#include "log/CustomLog.h"
+#include "log/File.h"
+#include "log/TcpLogger.h"
+#include "MemBlob.h"
+#include "Parsing.h"
+#include "SquidConfig.h"
+#include "SquidTime.h"
+
+// a single I/O buffer should be large enough to store any access.log record
+const size_t Log::TcpLogger::IoBufSize = 2*MAX_URL;
+
+// We need at least two buffers because when we write the first buffer,
+// we have to use the second buffer to accumulate new entries.
+const size_t Log::TcpLogger::BufferCapacityMin = 2*Log::TcpLogger::IoBufSize;
+
+#define MY_DEBUG_SECTION 50 /* Log file handling */
+
+CBDATA_NAMESPACED_CLASS_INIT(Log, TcpLogger);
+
+Log::TcpLogger::TcpLogger(size_t bufCap, bool dieOnErr, Ip::Address them):
+ AsyncJob("TcpLogger"),
+ dieOnError(dieOnErr),
+ bufferCapacity(bufCap),
+ bufferedSize(0),
+ flushDebt(0),
+ quitOnEmpty(false),
+ reconnectScheduled(false),
+ writeScheduled(false),
+ conn(NULL),
+ remote(them),
+ connectFailures(0),
+ drops(0)
+{
+ if (bufferCapacity < BufferCapacityMin) {
+ debugs(MY_DEBUG_SECTION, DBG_IMPORTANT,
+ "WARNING: tcp:" << remote << " logger configured buffer " <<
+ "size " << bufferCapacity << " is smaller than the " <<
+ BufferCapacityMin << "-byte" << " minimum. " <<
+ "Using the minimum instead.");
+ bufferCapacity = BufferCapacityMin;
+ }
+}
+
+Log::TcpLogger::~TcpLogger()
+{
+ // make sure Comm::Write does not have our buffer pointer
+ assert(!writeScheduled);
+}
+
+void
+Log::TcpLogger::start()
+{
+ connect();
+}
+
+bool
+Log::TcpLogger::doneAll() const
+{
+ debugs(MY_DEBUG_SECTION, 5, "quitOnEmpty: " << quitOnEmpty <<
+ " buffered: " << bufferedSize <<
+ " conn: " << conn << ' ' << connectFailures);
+
+ // we do not quit unless we are told that we may
+ if (!quitOnEmpty)
+ return false;
+
+ /* We were asked to quit after we are done writing buffers. Are we done? */
+
+ // If we have records but are failing to connect, quit. Otherwise, we may
+ // be trying to connect forever due to a [since fixed] misconfiguration!
+ const bool failingToConnect = !conn && connectFailures;
+ if (bufferedSize && !failingToConnect)
+ return false;
+
+ return AsyncJob::doneAll();
+}
+
+void
+Log::TcpLogger::swanSong()
+{
+ disconnect(); // optional: refcounting should close/delete conn eventually
+ AsyncJob::swanSong();
+}
+
+void
+Log::TcpLogger::endGracefully()
+{
+ // job call protection must end our job if we are done logging current bufs
+ assert(inCall != NULL);
+ quitOnEmpty = true;
+ flush();
+}
+
+void
+Log::TcpLogger::flush()
+{
+ flushDebt = bufferedSize;
+ writeIfNeeded();
+}
+
+void
+Log::TcpLogger::logRecord(const char *buf, const size_t len)
+{
+ appendRecord(buf, len);
+ writeIfNeeded();
+}
+
+/// starts writing if and only if it is time to write accumulated records
+void
+Log::TcpLogger::writeIfNeeded()
+{
+ // write if an earlier flush command forces us to write or
+ // if we have filled at least one I/O buffer
+ if (flushDebt > 0 || buffers.size() > 1)
+ writeIfPossible();
+}
+
+/// starts writing if possible
+void Log::TcpLogger::writeIfPossible()
+{
+ debugs(MY_DEBUG_SECTION, 7, "guards: " << (!writeScheduled) <<
+ (bufferedSize > 0) << (conn != NULL) <<
+ (conn != NULL && !fd_table[conn->fd].closing()) << " buffered: " <<
+ bufferedSize << '/' << buffers.size());
+
+ // XXX: Squid shutdown sequence starts closing our connection before
+ // calling LogfileClose, leading to loss of log records during shutdown.
+ if (!writeScheduled && bufferedSize > 0 && conn != NULL &&
+ !fd_table[conn->fd].closing()) {
+ debugs(MY_DEBUG_SECTION, 5, "writing first buffer");
+
+ typedef CommCbMemFunT<TcpLogger, CommIoCbParams> WriteDialer;
+ AsyncCall::Pointer callback = JobCallback(MY_DEBUG_SECTION, 5, WriteDialer, this, Log::TcpLogger::writeDone);
+ const MemBlob::Pointer &buffer = buffers.front();
+ Comm::Write(conn, buffer->mem, buffer->size, callback, NULL);
+ writeScheduled = true;
+ }
+}
+
+/// whether len more bytes can be buffered
+bool
+Log::TcpLogger::canFit(const size_t len) const
+{
+ // TODO: limit reporting frequency in addition to reporting only changes
+
+ if (bufferedSize+len <= bufferCapacity) {
+ if (drops) {
+ // We can get here if a shorter record accidentally fits after we
+ // started dropping records. When that happens, the following
+ // DBG_IMPORTANT message will mislead admin into thinking that
+ // the problem was resolved (for a brief period of time, until
+ // another record comes in and overflows the buffer). It is
+ // difficult to prevent this without also creating the opposite
+ // problem: A huge record that does not fit and is dropped blocks
+ // subsequent regular records from being buffered until we write.
+ debugs(MY_DEBUG_SECTION, DBG_IMPORTANT, "tcp:" << remote <<
+ " logger stops dropping records after " << drops << " drops" <<
+ "; current buffer use: " << (bufferedSize+len) <<
+ " out of " << bufferCapacity << " bytes");
+ }
+ return true;
+ }
+
+ if (!drops || dieOnError) {
+ debugs(MY_DEBUG_SECTION,
+ dieOnError ? DBG_CRITICAL : DBG_IMPORTANT,
+ "tcp:" << remote << " logger " << bufferCapacity << "-byte " <<
+ "buffer overflowed; cannot fit " <<
+ (bufferedSize+len-bufferCapacity) << " bytes");
+ }
+
+ if (dieOnError)
+ fatal("tcp logger buffer overflowed");
+
+ if (!drops) {
+ debugs(MY_DEBUG_SECTION, DBG_IMPORTANT, "tcp:" << remote <<
+ " logger starts dropping records.");
+ }
+
+ return false;
+}
+
+/// buffer a record that might exceed IoBufSize
+void
+Log::TcpLogger::appendRecord(const char *record, const size_t len)
+{
+ // they should not happen, but to be safe, let's protect drop start/stop
+ // monitoring algorithm from empty records (which can never be dropped)
+ if (!len)
+ return;
+
+ if (!canFit(len)) {
+ ++drops;
+ return;
+ }
+
+ drops = 0;
+ // append without spliting buf, unless it exceeds IoBufSize
+ for (size_t off = 0; off < len; off += IoBufSize)
+ appendChunk(record + off, min(len - off, IoBufSize));
+}
+
+/// buffer a record chunk without splitting it across buffers
+void
+Log::TcpLogger::appendChunk(const char *chunk, const size_t len)
+{
+ Must(len <= IoBufSize);
+ // add a buffer if there is not one that can accomodate len bytes
+ bool addBuffer = buffers.empty() ||
+ (buffers.back()->size+len > IoBufSize);
+ // also add a buffer if there is only one and that one is being written
+ addBuffer = addBuffer || (writeScheduled && buffers.size() == 1);
+
+ if (addBuffer) {
+ buffers.push_back(new MemBlob(IoBufSize));
+ debugs(MY_DEBUG_SECTION, 7, "added buffer #" << buffers.size());
+ }
+
+ Must(!buffers.empty());
+ buffers.back()->append(chunk, len);
+ bufferedSize += len;
+}
+
+/// starts [re]connecting to the remote logger
+void
+Log::TcpLogger::connect()
+{
+ if (shutting_down)
+ return;
+
+ debugs(MY_DEBUG_SECTION, 3, "connecting");
+ Must(!conn);
+
+ Comm::ConnectionPointer futureConn = new Comm::Connection;
+ futureConn->remote = remote;
+ futureConn->local.SetAnyAddr();
+ if (futureConn->remote.IsIPv4())
+ futureConn->local.SetIPv4();
+
+ typedef CommCbMemFunT<TcpLogger, CommConnectCbParams> Dialer;
+ AsyncCall::Pointer call = JobCallback(MY_DEBUG_SECTION, 5, Dialer, this, Log::TcpLogger::connectDone);
+ AsyncJob::Start(new Comm::ConnOpener(futureConn, call, 2));
+}
+
+/// Comm::ConnOpener callback
+void
+Log::TcpLogger::connectDone(const CommConnectCbParams ¶ms)
+{
+ if (params.flag != COMM_OK) {
+ const double delay = 0.5; // seconds
+ if (connectFailures++ % 100 == 0) {
+ debugs(MY_DEBUG_SECTION, DBG_IMPORTANT, "tcp:" << remote <<
+ " logger connection attempt #" << connectFailures <<
+ " failed. Will keep trying every " << delay << " seconds.");
+ }
+
+ if (!reconnectScheduled) {
+ reconnectScheduled = true;
+ eventAdd("Log::TcpLogger::DelayedReconnect",
+ Log::TcpLogger::DelayedReconnect,
+ new Pointer(this), 0.5, 0, false);
+ }
+ } else {
+ if (connectFailures > 0) {
+ debugs(MY_DEBUG_SECTION, DBG_IMPORTANT, "tcp:" << remote <<
+ " logger connectivity restored after " <<
+ (connectFailures+1) << " attempts.");
+ connectFailures = 0;
+ }
+
+ Must(!conn);
+ conn = params.conn;
+
+ Must(!closer);
+ typedef CommCbMemFunT<TcpLogger, CommCloseCbParams> Closer;
+ closer = JobCallback(MY_DEBUG_SECTION, 4, Closer, this, Log::TcpLogger::handleClosure);
+ comm_add_close_handler(conn->fd, closer);
+
+ writeIfNeeded();
+ }
+}
+
+// XXX: Needed until eventAdd() starts accepting Async calls directly.
+/// Log::TcpLogger::delayedReconnect() wrapper.
+void
+Log::TcpLogger::DelayedReconnect(void *data)
+{
+ Pointer *ptr = static_cast<Pointer*>(data);
+ assert(ptr);
+ if (TcpLogger *logger = ptr->valid()) {
+ // Get back inside AsyncJob protections by scheduling another call.
+ typedef NullaryMemFunT<TcpLogger> Dialer;
+ AsyncCall::Pointer call = JobCallback(MY_DEBUG_SECTION, 5, Dialer,
+ logger,
+ Log::TcpLogger::delayedReconnect);
+ ScheduleCallHere(call);
+ }
+ delete ptr;
+}
+
+/// "sleep a little before trying to connect again" event callback
+void
+Log::TcpLogger::delayedReconnect() {
+ Must(reconnectScheduled);
+ Must(!conn);
+ reconnectScheduled = false;
+ connect();
+}
+
+/// Comm::Write callback
+void
+Log::TcpLogger::writeDone(const CommIoCbParams &io)
+{
+ writeScheduled = false;
+ if (io.flag == COMM_ERR_CLOSING) {
+ debugs(MY_DEBUG_SECTION, 7, "closing");
+ // do nothing here -- our comm_close_handler will be called to clean up
+ } else
+ if (io.flag != COMM_OK) {
+ debugs(MY_DEBUG_SECTION, 2, "write failure: " << xstrerr(io.xerrno));
+ // keep the first buffer (the one we failed to write)
+ disconnect();
+ connect();
+ } else {
+ debugs(MY_DEBUG_SECTION, 5, "write successful");
+
+ Must(!buffers.empty()); // we had a buffer to write
+ const MemBlob::Pointer &written = buffers.front();
+ const size_t writtenSize = static_cast<size_t>(written->size);
+ // and we wrote the whole buffer
+ Must(io.size >= 0 && writtenSize >= 0 && io.size == writtenSize);
+ Must(bufferedSize >= writtenSize);
+ bufferedSize -= writtenSize;
+
+ buffers.pop_front();
+
+ if (flushDebt > io.size)
+ flushDebt -= io.size;
+ else
+ flushDebt = 0; // wrote everything we owed (or more)
+
+ writeIfNeeded();
+ }
+}
+
+/// This is our comm_close_handler. It is called when some external force
+/// (e.g., reconfigure or shutdown) is closing the connection (rather than us).
+void
+Log::TcpLogger::handleClosure(const CommCloseCbParams &io)
+{
+ assert(inCall != NULL);
+ closer = NULL;
+ conn = NULL;
+ // in all current use cases, we should not try to reconnect
+ mustStop("Log::TcpLogger::handleClosure");
+}
+
+/// close our connection now, without flushing
+void
+Log::TcpLogger::disconnect()
+{
+ if (conn != NULL) {
+ if (closer != NULL) {
+ comm_remove_close_handler(conn->fd, closer);
+ closer = NULL;
+ }
+ conn->close();
+ conn = NULL;
+ }
+}
+
+/// Converts Logfile into a pointer to a valid TcpLogger job or,
+/// if the logger job has quit, into a nill pointer
+Log::TcpLogger *
+Log::TcpLogger::StillLogging(Logfile *lf)
+{
+ if (Pointer *pptr = static_cast<Pointer*>(lf->data))
+ return pptr->get(); // may be nil
+ return NULL;
+}
+
+void
+Log::TcpLogger::Flush(Logfile * lf)
+{
+ if (TcpLogger *logger = StillLogging(lf))
+ logger->flush();
+}
+
+void
+Log::TcpLogger::WriteLine(Logfile * lf, const char *buf, size_t len)
+{
+ if (TcpLogger *logger = StillLogging(lf))
+ logger->logRecord(buf, len);
+}
+
+void
+Log::TcpLogger::StartLine(Logfile * lf)
+{
+}
+
+void
+Log::TcpLogger::EndLine(Logfile * lf)
+{
+ if (!Config.onoff.buffered_logs)
+ Flush(lf);
+}
+
+void
+Log::TcpLogger::Rotate(Logfile * lf)
+{
+}
+
+void
+Log::TcpLogger::Close(Logfile * lf)
+{
+ if (TcpLogger *logger = StillLogging(lf)) {
+ debugs(50, 3, "Closing " << logger);
+ typedef NullaryMemFunT<TcpLogger> Dialer;
+ Dialer dialer(logger, &Log::TcpLogger::endGracefully);
+ AsyncCall::Pointer call = asyncCall(50, 3, "Log::TcpLogger::endGracefully", dialer);
+ ScheduleCallHere(call);
+ }
+ delete static_cast<Pointer*>(lf->data);
+ lf->data = NULL;
+}
+
+/*
+ * This code expects the path to be //host:port
+ */
+int
+Log::TcpLogger::Open(Logfile * lf, const char *path, size_t bufsz, int fatalFlag)
+{
+ assert(!StillLogging(lf));
+ debugs(5, 3, "Tcp Open called");
+
+ Ip::Address addr;
+
+ if (strncmp(path, "//", 2) == 0)
+ path += 2;
+ char *strAddr = xstrdup(path);
+ if (!GetHostWithPort(strAddr, &addr)) {
+ if (lf->flags.fatal) {
+ fatalf("Invalid TCP logging address '%s'\n", lf->path);
+ } else {
+ debugs(50, DBG_IMPORTANT, "Invalid TCP logging address '" << lf->path << "'");
+ safe_free(strAddr);
+ return FALSE;
+ }
+ }
+ safe_free(strAddr);
+
+ TcpLogger *logger = new TcpLogger(bufsz, fatalFlag, addr);
+ lf->data = new Pointer(logger);
+ lf->f_close = &Close;
+ lf->f_linewrite = &WriteLine;
+ lf->f_linestart = &StartLine;
+ lf->f_lineend = &EndLine;
+ lf->f_flush = &Flush;
+ lf->f_rotate = &Rotate;
+ AsyncJob::Start(logger);
+
+ return 1;
+}
--- /dev/null
+#ifndef _SQUID_SRC_LOG_TCPLOGGER_H
+#define _SQUID_SRC_LOG_TCPLOGGER_H
+
+#include "base/AsyncJob.h"
+#include "ip/Address.h"
+
+#if HAVE_LIST
+#include <list>
+#endif
+
+class MemBlob;
+typedef RefCount<MemBlob> MemBlobPointer;
+
+namespace Log {
+
+/**
+ * Sends log records to a remote TCP logger at the configured IP:port address.
+ * Handles loss of connectivity, record buffering, and buffer overflows.
+ */
+class TcpLogger : public AsyncJob
+{
+public:
+ typedef CbcPointer<TcpLogger> Pointer;
+
+ /* Logfile API */
+ static int Open(Logfile *lf, const char *path, size_t bufSz, int fatalFlag);
+
+protected:
+ TcpLogger(size_t, bool, Ip::Address);
+ virtual ~TcpLogger();
+
+ /// Called when Squid is reconfiguring (or exiting) to give us a chance to
+ /// flush remaining buffers and end this job w/o loss of data. No new log
+ /// records are expected. Must be used as (or inside) an async job call and
+ /// will result in [eventual] job termination.
+ void endGracefully();
+
+ /// buffers record and possibly writes it to the remote logger
+ void logRecord(const char *buf, size_t len);
+
+ /// write all currently buffered records ASAP
+ void flush();
+
+ /* AsyncJob API */
+ virtual void start();
+ virtual bool doneAll() const;
+ virtual void swanSong();
+
+private:
+ /* Logfile API. Map c-style Logfile calls to TcpLogger method calls. */
+ static void Flush(Logfile *lf);
+ static void WriteLine(Logfile *lf, const char *buf, size_t len);
+ static void StartLine(Logfile *lf);
+ static void EndLine(Logfile *lf);
+ static void Rotate(Logfile *lf);
+ static void Close(Logfile *lf);
+
+ static TcpLogger *StillLogging(Logfile *lf);
+
+ static void DelayedReconnect(void *data);
+ void delayedReconnect();
+
+ bool canFit(const size_t len) const;
+ void appendRecord(const char *buf, size_t len);
+ void appendChunk(const char *chunk, const size_t len);
+ void writeIfNeeded();
+ void writeIfPossible();
+ void connect();
+ void disconnect();
+
+ /* comm callbacks */
+ void connectDone(const CommConnectCbParams &conn);
+ void writeDone(const CommIoCbParams &io);
+ void handleClosure(const CommCloseCbParams &io);
+
+ static const size_t IoBufSize; ///< fixed I/O buffer size
+ static const size_t BufferCapacityMin; ///< minimum bufferCapacity value
+
+ /// Whether this job must kill Squid on the first unrecoverable error.
+ /// Note that we may be able to recover from a failure to connect, but we
+ /// cannot recover from forgetting (dropping) a record while connecting.
+ bool dieOnError;
+
+ std::list<MemBlobPointer> buffers; ///< I/O buffers
+ size_t bufferCapacity; ///< bufferedSize limit
+ size_t bufferedSize; ///< number of log record bytes stored in RAM now
+ size_t flushDebt; ///< how many record bytes we still need to write ASAP
+
+ bool quitOnEmpty; ///< whether this job should quit when buffers are empty
+ bool reconnectScheduled; ///< we are sleeping before the next connection attempt
+ bool writeScheduled; ///< we are waiting for the latest write() results
+
+ Comm::ConnectionPointer conn; ///< opened connection to the remote logger
+ Ip::Address remote; ///< where the remote logger expects our records
+ AsyncCall::Pointer closer; ///< handles unexpected/external conn closures
+
+ uint64_t connectFailures; ///< number of sequential connection failures
+ uint64_t drops; ///< number of records dropped during the current outage
+
+ CBDATA_CLASS2(TcpLogger);
+};
+
+} // namespace Log
+
+#endif /* _SQUID_SRC_LOG_TCPLOGGER_H */
if (log->type == Log::Format::CLF_NONE)
continue;
- log->logfile = logfileOpen(log->filename, MAX_URL << 2, 1);
+ log->logfile = logfileOpen(log->filename, log->bufferSize, log->fatal);
LogfileStatus = LOG_ENABLE;
projects / thirdparty / squid.git / commitdiff
