/* * $Id: access_log.c,v 1.104.2.1 2008/03/18 02:48:43 hno Exp $ * * DEBUG: section 46 Access Log * AUTHOR: Duane Wessels * * 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" #if HEADERS_LOG static Logfile *headerslog = NULL; #endif #if MULTICAST_MISS_STREAM static int mcast_miss_fd = -1; static struct sockaddr_in mcast_miss_to; static void mcast_encode(unsigned int *, size_t, const unsigned int *); #endif #if FORW_VIA_DB typedef struct { hash_link hash; int n; } fvdb_entry; static hash_table *via_table = NULL; static hash_table *forw_table = NULL; static void fvdbInit(void); static void fvdbDumpTable(StoreEntry * e, hash_table * hash); static void fvdbCount(hash_table * hash, const char *key); static OBJH fvdbDumpVia; static OBJH fvdbDumpForw; static FREE fvdbFreeEntry; static void fvdbClear(void); #endif static int LogfileStatus = LOG_DISABLE; #define LOG_BUF_SZ (MAX_URL<<2) static const char c2x[] = "000102030405060708090a0b0c0d0e0f" "101112131415161718191a1b1c1d1e1f" "202122232425262728292a2b2c2d2e2f" "303132333435363738393a3b3c3d3e3f" "404142434445464748494a4b4c4d4e4f" "505152535455565758595a5b5c5d5e5f" "606162636465666768696a6b6c6d6e6f" "707172737475767778797a7b7c7d7e7f" "808182838485868788898a8b8c8d8e8f" "909192939495969798999a9b9c9d9e9f" "a0a1a2a3a4a5a6a7a8a9aaabacadaeaf" "b0b1b2b3b4b5b6b7b8b9babbbcbdbebf" "c0c1c2c3c4c5c6c7c8c9cacbcccdcecf" "d0d1d2d3d4d5d6d7d8d9dadbdcdddedf" "e0e1e2e3e4e5e6e7e8e9eaebecedeeef" "f0f1f2f3f4f5f6f7f8f9fafbfcfdfeff"; /* log_quote -- URL-style encoding on MIME headers. */ char * log_quote(const char *header) { int c; int i; char *buf; char *buf_cursor; if (header == NULL) { buf = xcalloc(1, 1); *buf = '\0'; return buf; } buf = xcalloc(1, (strlen(header) * 3) + 1); buf_cursor = buf; /* * We escape: \x00-\x1F"#%;<>?{}|\\\\^~`\[\]\x7F-\xFF * which is the default escape list for the CPAN Perl5 URI module * modulo the inclusion of space (x40) to make the raw logs a bit * more readable. */ while ((c = *(const unsigned char *) header++) != '\0') { #if !OLD_LOG_MIME if (c == '\r') { *buf_cursor++ = '\\'; *buf_cursor++ = 'r'; } else if (c == '\n') { *buf_cursor++ = '\\'; *buf_cursor++ = 'n'; } else #endif if (c <= 0x1F || c >= 0x7F || c == '%' #if OLD_LOG_MIME || c == '"' || c == '#' || c == ';' || c == '<' || c == '>' || c == '?' || c == '{' || c == '}' || c == '|' || c == '\\' || c == '^' || c == '~' || c == '`' #endif || c == '[' || c == ']') { *buf_cursor++ = '%'; i = c * 2; *buf_cursor++ = c2x[i]; *buf_cursor++ = c2x[i + 1]; #if !OLD_LOG_MIME } else if (c == '\\') { *buf_cursor++ = '\\'; *buf_cursor++ = '\\'; #endif } else { *buf_cursor++ = (char) c; } } *buf_cursor = '\0'; return buf; } static char * username_quote(const char *header) /* copy of log_quote. Bugs there will be found here */ { int c; int i; char *buf; char *buf_cursor; if (header == NULL) { buf = xcalloc(1, 1); *buf = '\0'; return buf; } buf = xcalloc(1, (strlen(header) * 3) + 1); buf_cursor = buf; /* * We escape: space \x00-\x1F and space (0x40) and \x7F-\xFF * to prevent garbage in the logs. CR and LF are also there just in case. */ while ((c = *(const unsigned char *) header++) != '\0') { if (c == '\r') { *buf_cursor++ = '\\'; *buf_cursor++ = 'r'; } else if (c == '\n') { *buf_cursor++ = '\\'; *buf_cursor++ = 'n'; } else if (c <= 0x1F || c >= 0x7F || c == '%' || c == ' ') { *buf_cursor++ = '%'; i = c * 2; *buf_cursor++ = c2x[i]; *buf_cursor++ = c2x[i + 1]; } else { *buf_cursor++ = (char) c; } } *buf_cursor = '\0'; return buf; } static char * accessLogFormatName(const char *name) { if (NULL == name) return NULL; if (name[0] == '\0') return NULL; return username_quote(name); } static char * log_quoted_string(const char *str) { char *out = xmalloc(strlen(str) * 2 + 1); char *p = out; while (*str) { int l = strcspn(str, "\"\\\r\n\t"); memcpy(p, str, l); str += l; p += l; switch (*str) { case '\0': break; case '\r': *p++ = '\\'; *p++ = 'r'; str++; break; case '\n': *p++ = '\\'; *p++ = 'n'; str++; break; case '\t': *p++ = '\\'; *p++ = 't'; str++; break; default: *p++ = '\\'; *p++ = *str; str++; break; } } *p++ = '\0'; return out; } /* * Bytecodes for the configureable logformat stuff */ typedef enum { LFT_NONE, /* dummy */ LFT_STRING, LFT_CLIENT_IP_ADDRESS, LFT_CLIENT_FQDN, LFT_CLIENT_PORT, /*LFT_SERVER_IP_ADDRESS, */ LFT_SERVER_IP_OR_PEER_NAME, LFT_OUTGOING_IP, /*LFT_SERVER_PORT, */ LFT_LOCAL_IP, LFT_LOCAL_PORT, /*LFT_LOCAL_NAME, */ LFT_TIME_SECONDS_SINCE_EPOCH, LFT_TIME_SUBSECOND, LFT_TIME_LOCALTIME, LFT_TIME_GMT, LFT_TIME_TO_HANDLE_REQUEST, LFT_REQUEST_HEADER, LFT_REQUEST_HEADER_ELEM, LFT_REQUEST_ALL_HEADERS, LFT_REPLY_HEADER, LFT_REPLY_HEADER_ELEM, LFT_REPLY_ALL_HEADERS, LFT_USER_NAME, LFT_USER_LOGIN, /*LFT_USER_REALM, */ /*LFT_USER_SCHEME, */ LFT_USER_IDENT, LFT_USER_EXT, #if USE_SSL LFT_USER_SSL, #endif LFT_HTTP_CODE, /*LFT_HTTP_STATUS, */ LFT_SQUID_STATUS, /*LFT_SQUID_ERROR, */ LFT_SQUID_HIERARCHY, LFT_MIME_TYPE, LFT_REQUEST_METHOD, LFT_REQUEST_URI, LFT_REQUEST_URLPATH, /*LFT_REQUEST_QUERY, * // * this is not needed. see strip_query_terms */ LFT_REQUEST_VERSION, LFT_REQUEST_SIZE_TOTAL, /*LFT_REQUEST_SIZE_LINE, */ /*LFT_REQUEST_SIZE_HEADERS, */ /*LFT_REQUEST_SIZE_BODY, */ /*LFT_REQUEST_SIZE_BODY_NO_TE, */ LFT_REPLY_SIZE_TOTAL, /*LFT_REPLY_SIZE_LINE, */ /*LFT_REPLY_SIZE_HEADERS, */ /*LFT_REPLY_SIZE_BODY, */ /*LFT_REPLY_SIZE_BODY_NO_TE, */ LFT_IO_SIZE_TOTAL, LFT_EXT_LOG, LFT_SEQUENCE_NUMBER, LFT_EXT_FRESHNESS, LFT_PERCENT /* special string cases for escaped chars */ } logformat_bcode_t; enum log_quote { LOG_QUOTE_NONE = 0, LOG_QUOTE_QUOTES, LOG_QUOTE_BRAKETS, LOG_QUOTE_URL, LOG_QUOTE_RAW }; struct _logformat_token { logformat_bcode_t type; union { char *string; struct { char *header; char *element; char separator; } header; char *timespec; } data; unsigned char width; unsigned char precision; enum log_quote quote:3; unsigned int left:1; unsigned int space:1; unsigned int zero:1; int divisor; logformat_token *next; /* todo: move from linked list to array */ }; struct logformat_token_table_entry { const char *config; logformat_bcode_t token_type; int options; }; struct logformat_token_table_entry logformat_token_table[] = { {">a", LFT_CLIENT_IP_ADDRESS}, {">p", LFT_CLIENT_PORT}, {">A", LFT_CLIENT_FQDN}, /*{ "h", LFT_REQUEST_HEADER}, {">h", LFT_REQUEST_ALL_HEADERS}, {"v", LFT_REQUEST_VERSION}, {"rv", LFT_REQUEST_VERSION}, {">st", LFT_REQUEST_SIZE_TOTAL}, /*{ ">sl", LFT_REQUEST_SIZE_LINE }, * / / * the request line "GET ... " */ /*{ ">sh", LFT_REQUEST_SIZE_HEADERS }, */ /*{ ">sb", LFT_REQUEST_SIZE_BODY }, */ /*{ ">sB", LFT_REQUEST_SIZE_BODY_NO_TE }, */ {"sn", LFT_SEQUENCE_NUMBER}, {"logFormat; logfile = log->logfile; for (fmt = lf->format; fmt != NULL; fmt = fmt->next) { /* for each token */ const char *out = NULL; int quote = 0; squid_off_t outint = 0; int doint = 0; int dofree = 0; switch (fmt->type) { case LFT_NONE: out = ""; break; case LFT_STRING: out = fmt->data.string; break; case LFT_CLIENT_IP_ADDRESS: out = inet_ntoa(al->cache.caddr); break; case LFT_CLIENT_FQDN: out = fqdncache_gethostbyaddr(al->cache.caddr, FQDN_LOOKUP_IF_MISS); if (!out) out = inet_ntoa(al->cache.caddr); break; case LFT_CLIENT_PORT: if (al->request) { outint = al->request->client_port; doint = 1; } break; /* case LFT_SERVER_IP_ADDRESS: */ case LFT_SERVER_IP_OR_PEER_NAME: out = al->hier.host; break; case LFT_OUTGOING_IP: out = xstrdup(inet_ntoa(al->cache.out_ip)); break; /* case LFT_SERVER_PORT: */ case LFT_LOCAL_IP: if (al->request) out = inet_ntoa(al->request->my_addr); break; case LFT_LOCAL_PORT: if (al->request) { outint = al->request->my_port; doint = 1; } break; case LFT_TIME_SECONDS_SINCE_EPOCH: outint = current_time.tv_sec; doint = 1; break; case LFT_TIME_SUBSECOND: outint = current_time.tv_usec / fmt->divisor; doint = 1; break; case LFT_TIME_LOCALTIME: case LFT_TIME_GMT: { const char *spec; struct tm *t; spec = fmt->data.timespec; if (!spec) spec = "%d/%b/%Y:%H:%M:%S %z"; if (fmt->type == LFT_TIME_LOCALTIME) t = localtime(&squid_curtime); else t = gmtime(&squid_curtime); strftime(tmp, sizeof(tmp), spec, t); out = tmp; } break; case LFT_TIME_TO_HANDLE_REQUEST: outint = al->cache.msec; doint = 1; break; case LFT_REQUEST_HEADER: if (al->request) sb = httpHeaderGetByName(&al->request->header, fmt->data.header.header); out = strBuf(sb); quote = 1; break; case LFT_REPLY_HEADER: if (al->reply) sb = httpHeaderGetByName(&al->reply->header, fmt->data.header.header); out = strBuf(sb); quote = 1; break; case LFT_REQUEST_HEADER_ELEM: if (al->request) sb = httpHeaderGetByNameListMember(&al->request->header, fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator); out = strBuf(sb); quote = 1; break; case LFT_REPLY_HEADER_ELEM: if (al->reply) sb = httpHeaderGetByNameListMember(&al->reply->header, fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator); out = strBuf(sb); quote = 1; break; case LFT_REQUEST_ALL_HEADERS: out = al->headers.request; quote = 1; break; case LFT_REPLY_ALL_HEADERS: out = al->headers.reply; quote = 1; break; case LFT_USER_NAME: out = al->cache.authuser; if (!out || !*out) out = al->cache.rfc931; #if USE_SSL if (!out || !*out) out = al->cache.ssluser; #endif quote = 1; break; case LFT_USER_LOGIN: out = al->cache.authuser; quote = 1; break; case LFT_USER_IDENT: out = al->cache.rfc931; quote = 1; break; /* case LFT_USER_REALM: */ /* case LFT_USER_SCHEME: */ #if USE_SSL case LFT_USER_SSL: out = al->cache.ssluser; quote = 1; break; #endif case LFT_USER_EXT: if (al->request) out = strBuf(al->request->extacl_log); quote = 1; break; case LFT_HTTP_CODE: outint = al->http.code; doint = 1; break; /* case LFT_HTTP_STATUS: * out = statusline->text; * quote = 1; * break; */ case LFT_SQUID_STATUS: out = log_tags[al->cache.code]; break; /* case LFT_SQUID_ERROR: */ case LFT_SQUID_HIERARCHY: if (al->hier.ping.timedout) memBufAppend(&mb, "TIMEOUT_", 8); out = hier_strings[al->hier.code]; break; case LFT_MIME_TYPE: out = al->http.content_type; break; case LFT_REQUEST_METHOD: out = al->private.method_str; break; case LFT_REQUEST_URI: out = rfc1738_escape_unescaped(al->url); break; case LFT_REQUEST_URLPATH: if (al->request) { out = strBuf(al->request->urlpath); quote = 1; } break; case LFT_REQUEST_VERSION: snprintf(tmp, sizeof(tmp), "%d.%d", (int) al->http.version.major, (int) al->http.version.minor); out = tmp; break; case LFT_REQUEST_SIZE_TOTAL: outint = al->cache.rq_size; doint = 1; break; /*case LFT_REQUEST_SIZE_LINE: */ /*case LFT_REQUEST_SIZE_HEADERS: */ /*case LFT_REQUEST_SIZE_BODY: */ /*case LFT_REQUEST_SIZE_BODY_NO_TE: */ case LFT_REPLY_SIZE_TOTAL: outint = al->cache.size; doint = 1; break; /*case LFT_REPLY_SIZE_LINE: */ /*case LFT_REPLY_SIZE_HEADERS: */ /*case LFT_REPLY_SIZE_BODY: */ /*case LFT_REPLY_SIZE_BODY_NO_TE: */ case LFT_IO_SIZE_TOTAL: outint = al->cache.size + al->cache.rq_size; doint = 1; break; case LFT_EXT_LOG: if (al->request) out = strBuf(al->request->extacl_log); quote = 1; break; case LFT_SEQUENCE_NUMBER: outint = LOGFILE_SEQNO(logfile); doint = 1; break; case LFT_EXT_FRESHNESS: out = al->ext_refresh; quote = 1; break; case LFT_PERCENT: out = "%"; break; } if (doint) { snprintf(tmp, sizeof(tmp), "%0*" PRINTF_OFF_T, fmt->zero ? (int) fmt->width : 0, outint); out = tmp; } if (out && *out) { if (quote || fmt->quote != LOG_QUOTE_NONE) { char *newout = NULL; int newfree = 0; switch (fmt->quote) { case LOG_QUOTE_NONE: newout = rfc1738_escape_unescaped(out); break; case LOG_QUOTE_QUOTES: newout = log_quoted_string(out); newfree = 1; break; case LOG_QUOTE_BRAKETS: newout = log_quote(out); newfree = 1; break; case LOG_QUOTE_URL: newout = rfc1738_escape(out); break; case LOG_QUOTE_RAW: break; } if (newout) { if (dofree) safe_free(out); out = newout; dofree = newfree; } } if (fmt->width) { if (fmt->left) memBufPrintf(&mb, "%-*s", (int) fmt->width, out); else memBufPrintf(&mb, "%*s", (int) fmt->width, out); } else memBufAppend(&mb, out, strlen(out)); } else { memBufAppend(&mb, "-", 1); } if (fmt->space) memBufAppend(&mb, " ", 1); stringClean(&sb); if (dofree) safe_free(out); } logfilePrintf(logfile, "%s\n", mb.buf); } /* parses a single token. Returns the token length in characters, * and fills in the lt item with the token information. * def is for sure null-terminated */ static int accessLogGetNewLogFormatToken(logformat_token * lt, char *def, enum log_quote *quote) { char *cur = def; struct logformat_token_table_entry *lte; int l; memset(lt, 0, sizeof(*lt)); l = strcspn(cur, "%"); if (l > 0) { char *cp; /* it's a string for sure, until \0 or the next % */ cp = xmalloc(l + 1); xstrncpy(cp, cur, l + 1); lt->type = LFT_STRING; lt->data.string = cp; while (l > 0) { switch (*cur) { case '"': if (*quote == LOG_QUOTE_NONE) *quote = LOG_QUOTE_QUOTES; else if (*quote == LOG_QUOTE_QUOTES) *quote = LOG_QUOTE_NONE; break; case '[': if (*quote == LOG_QUOTE_NONE) *quote = LOG_QUOTE_BRAKETS; break; case ']': if (*quote == LOG_QUOTE_BRAKETS) *quote = LOG_QUOTE_NONE; break; } cur++; l--; } goto done; } if (!*cur) goto done; cur++; switch (*cur) { case '"': lt->quote = LOG_QUOTE_QUOTES; cur++; break; case '\'': lt->quote = LOG_QUOTE_RAW; cur++; break; case '[': lt->quote = LOG_QUOTE_BRAKETS; cur++; break; case '#': lt->quote = LOG_QUOTE_URL; cur++; break; default: lt->quote = *quote; break; } if (*cur == '-') { lt->left = 1; cur++; } if (*cur == '0') { lt->zero = 1; cur++; } if (xisdigit(*cur)) lt->width = strtol(cur, &cur, 10); if (*cur == '.') lt->precision = strtol(cur + 1, &cur, 10); if (*cur == '{') { char *cp; cur++; l = strcspn(cur, "}"); cp = xmalloc(l + 1); xstrncpy(cp, cur, l + 1); lt->data.string = cp; cur += l; if (*cur == '}') cur++; } lt->type = LFT_NONE; for (lte = logformat_token_table; lte->config != NULL; lte++) { if (strncmp(lte->config, cur, strlen(lte->config)) == 0) { lt->type = lte->token_type; cur += strlen(lte->config); break; } } if (lt->type == LFT_NONE) { fatalf("Can't parse configuration token: '%s'\n", def); } if (*cur == ' ') { lt->space = 1; cur++; } done: switch (lt->type) { case LFT_REQUEST_HEADER: case LFT_REPLY_HEADER: if (lt->data.string) { char *header = lt->data.string; char *cp = strchr(header, ':'); if (cp) { *cp++ = '\0'; if (*cp == ',' || *cp == ';' || *cp == ':') lt->data.header.separator = *cp++; else lt->data.header.separator = ','; lt->data.header.element = cp; lt->type = (lt->type == LFT_REQUEST_HEADER) ? LFT_REQUEST_HEADER_ELEM : LFT_REPLY_HEADER_ELEM; } lt->data.header.header = header; } else { lt->type = (lt->type == LFT_REQUEST_HEADER) ? LFT_REQUEST_ALL_HEADERS : LFT_REPLY_ALL_HEADERS; Config.onoff.log_mime_hdrs = 1; } break; case LFT_CLIENT_FQDN: Config.onoff.log_fqdn = 1; break; case LFT_TIME_SUBSECOND: lt->divisor = 1000; if (lt->precision) { int i; lt->divisor = 1000000; for (i = lt->precision; i > 1; i--) lt->divisor /= 10; if (!lt->divisor) lt->divisor = 0; } break; default: break; } return (cur - def); } int accessLogParseLogFormat(logformat_token ** fmt, char *def) { char *cur, *eos; logformat_token *new_lt, *last_lt; enum log_quote quote = LOG_QUOTE_NONE; debug(46, 1) ("accessLogParseLogFormat: got definition '%s'\n", def); /* very inefficent parser, but who cares, this needs to be simple */ /* First off, let's tokenize, we'll optimize in a second pass. * A token can either be a %-prefixed sequence (usually a dynamic * token but it can be an escaped sequence), or a string. */ cur = def; eos = def + strlen(def); *fmt = new_lt = last_lt = xmalloc(sizeof(logformat_token)); cur += accessLogGetNewLogFormatToken(new_lt, cur, "e); while (cur < eos) { new_lt = xmalloc(sizeof(logformat_token)); last_lt->next = new_lt; last_lt = new_lt; cur += accessLogGetNewLogFormatToken(new_lt, cur, "e); } return 1; } void accessLogDumpLogFormat(StoreEntry * entry, const char *name, logformat * definitions) { logformat_token *t; logformat *format; struct logformat_token_table_entry *te; debug(46, 4) ("accessLogDumpLogFormat called\n"); for (format = definitions; format; format = format->next) { debug(46, 4) ("Dumping logformat definition for %s\n", format->name); storeAppendPrintf(entry, "logformat %s ", format->name); for (t = format->format; t; t = t->next) { if (t->type == LFT_STRING) storeAppendPrintf(entry, "%s", t->data.string); else { char argbuf[256]; char *arg = NULL; logformat_bcode_t type = t->type; switch (type) { /* special cases */ case LFT_STRING: break; case LFT_REQUEST_HEADER_ELEM: case LFT_REPLY_HEADER_ELEM: if (t->data.header.separator != ',') snprintf(argbuf, sizeof(argbuf), "%s:%c%s", t->data.header.header, t->data.header.separator, t->data.header.element); else snprintf(argbuf, sizeof(argbuf), "%s:%s", t->data.header.header, t->data.header.element); arg = argbuf; type = (type == LFT_REQUEST_HEADER_ELEM) ? LFT_REQUEST_HEADER : LFT_REPLY_HEADER; break; case LFT_REQUEST_ALL_HEADERS: case LFT_REPLY_ALL_HEADERS: type = (type == LFT_REQUEST_ALL_HEADERS) ? LFT_REQUEST_HEADER : LFT_REPLY_HEADER; break; default: if (t->data.string) arg = t->data.string; break; } storeAppend(entry, "%", 1); switch (t->quote) { case LOG_QUOTE_QUOTES: storeAppend(entry, "\"", 1); break; case LOG_QUOTE_BRAKETS: storeAppend(entry, "[", 1); break; case LOG_QUOTE_URL: storeAppend(entry, "#", 1); break; case LOG_QUOTE_RAW: storeAppend(entry, "'", 1); break; case LOG_QUOTE_NONE: break; } if (t->left) storeAppend(entry, "-", 1); if (t->zero) storeAppend(entry, "0", 1); if (t->width) storeAppendPrintf(entry, "%d", (int) t->width); if (t->precision) storeAppendPrintf(entry, ".%d", (int) t->precision); if (arg) storeAppendPrintf(entry, "{%s}", arg); for (te = logformat_token_table; te->config != NULL; te++) { if (te->token_type == t->type) { storeAppendPrintf(entry, "%s", te->config); break; } } if (t->space) storeAppend(entry, " ", 1); assert(te->config != NULL); } } storeAppend(entry, "\n", 1); } } void accessLogFreeLogFormat(logformat_token ** tokens) { while (*tokens) { logformat_token *token = *tokens; *tokens = token->next; safe_free(token->data.string); xfree(token); } } static void accessLogSquid(AccessLogEntry * al, Logfile * logfile) { const char *client = NULL; const char *user = NULL; if (Config.onoff.log_fqdn) client = fqdncache_gethostbyaddr(al->cache.caddr, FQDN_LOOKUP_IF_MISS); if (client == NULL) client = inet_ntoa(al->cache.caddr); user = accessLogFormatName(al->cache.authuser); if (!user) user = accessLogFormatName(al->cache.rfc931); #if USE_SSL if (!user) user = accessLogFormatName(al->cache.ssluser); #endif if (user && !*user) safe_free(user); if (!Config.onoff.log_mime_hdrs) { logfilePrintf(logfile, "%9ld.%03d %6d %s %s/%03d %" PRINTF_OFF_T " %s %s %s %s%s/%s %s\n", (long int) current_time.tv_sec, (int) current_time.tv_usec / 1000, al->cache.msec, client, log_tags[al->cache.code], al->http.code, al->cache.size, al->private.method_str, rfc1738_escape_unescaped(al->url), user ? user : dash_str, al->hier.ping.timedout ? "TIMEOUT_" : "", hier_strings[al->hier.code], al->hier.host, al->http.content_type); } else { char *ereq = log_quote(al->headers.request); char *erep = log_quote(al->headers.reply); logfilePrintf(logfile, "%9ld.%03d %6d %s %s/%03d %" PRINTF_OFF_T " %s %s %s %s%s/%s %s [%s] [%s]\n", (long int) current_time.tv_sec, (int) current_time.tv_usec / 1000, al->cache.msec, client, log_tags[al->cache.code], al->http.code, al->cache.size, al->private.method_str, rfc1738_escape_unescaped(al->url), user ? user : dash_str, al->hier.ping.timedout ? "TIMEOUT_" : "", hier_strings[al->hier.code], al->hier.host, al->http.content_type, ereq, erep); safe_free(ereq); safe_free(erep); } safe_free(user); } static void accessLogCommon(AccessLogEntry * al, Logfile * logfile) { const char *client = NULL; char *user1 = NULL, *user2 = NULL; if (Config.onoff.log_fqdn) client = fqdncache_gethostbyaddr(al->cache.caddr, 0); if (client == NULL) client = inet_ntoa(al->cache.caddr); user1 = accessLogFormatName(al->cache.authuser); user2 = accessLogFormatName(al->cache.rfc931); logfilePrintf(logfile, "%s %s %s [%s] \"%s %s HTTP/%d.%d\" %d %" PRINTF_OFF_T " %s:%s", client, user2 ? user2 : dash_str, user1 ? user1 : dash_str, mkhttpdlogtime(&squid_curtime), al->private.method_str, rfc1738_escape_unescaped(al->url), al->http.version.major, al->http.version.minor, al->http.code, al->cache.size, log_tags[al->cache.code], hier_strings[al->hier.code]); safe_free(user1); safe_free(user2); if (Config.onoff.log_mime_hdrs) { char *ereq = log_quote(al->headers.request); char *erep = log_quote(al->headers.reply); logfilePrintf(logfile, " [%s] [%s]\n", ereq, erep); safe_free(ereq); safe_free(erep); } else { logfilePrintf(logfile, "\n"); } } void accessLogLog(AccessLogEntry * al, aclCheck_t * checklist) { customlog *log; if (LogfileStatus != LOG_ENABLE) return; if (al->url == NULL) al->url = dash_str; if (!al->http.content_type || *al->http.content_type == '\0') al->http.content_type = dash_str; if (al->icp.opcode) al->private.method_str = icp_opcode_str[al->icp.opcode]; else al->private.method_str = RequestMethods[al->http.method].str; if (al->hier.host[0] == '\0') xstrncpy(al->hier.host, dash_str, SQUIDHOSTNAMELEN); for (log = Config.Log.accesslogs; log; log = log->next) { if (checklist && log->aclList && aclMatchAclList(log->aclList, checklist) != 1) continue; if (log->logfile) { logfileLineStart(log->logfile); switch (log->type) { case CLF_AUTO: if (Config.onoff.common_log) accessLogCommon(al, log->logfile); else accessLogSquid(al, log->logfile); break; case CLF_SQUID: accessLogSquid(al, log->logfile); break; case CLF_COMMON: accessLogCommon(al, log->logfile); break; case CLF_CUSTOM: accessLogCustom(al, log); break; case CLF_NONE: goto last; default: fatalf("Unknown log format %d\n", log->type); break; } logfileLineEnd(log->logfile); } if (!checklist) break; } last: (void) 0; /* NULL statement for label */ #if MULTICAST_MISS_STREAM if (al->cache.code != LOG_TCP_MISS) (void) 0; else if (al->http.method != METHOD_GET) (void) 0; else if (mcast_miss_fd < 0) (void) 0; else { unsigned int ibuf[365]; size_t isize; xstrncpy((char *) ibuf, al->url, 364 * sizeof(int)); isize = ((strlen(al->url) + 8) / 8) * 2; if (isize > 364) isize = 364; mcast_encode((unsigned int *) ibuf, isize, (const unsigned int *) Config.mcast_miss.encode_key); comm_udp_sendto(mcast_miss_fd, &mcast_miss_to, sizeof(mcast_miss_to), ibuf, isize * sizeof(int)); } #endif } void accessLogRotate(void) { customlog *log; #if FORW_VIA_DB fvdbClear(); #endif for (log = Config.Log.accesslogs; log; log = log->next) { if (log->logfile) { logfileRotate(log->logfile); } } #if HEADERS_LOG logfileRotate(headerslog); #endif } void accessLogClose(void) { customlog *log; for (log = Config.Log.accesslogs; log; log = log->next) { if (log->logfile) { logfileClose(log->logfile); log->logfile = NULL; } } #if HEADERS_LOG logfileClose(headerslog); headerslog = NULL; #endif } void hierarchyNote(HierarchyLogEntry * hl, hier_code code, const char *cache_peer) { assert(hl != NULL); hl->code = code; xstrncpy(hl->host, cache_peer, SQUIDHOSTNAMELEN); } void accessLogInit(void) { customlog *log; for (log = Config.Log.accesslogs; log; log = log->next) { if (log->type == CLF_NONE) continue; log->logfile = logfileOpen(log->filename, MAX_URL << 2, 1); LogfileStatus = LOG_ENABLE; } #if HEADERS_LOG headerslog = logfileOpen("/usr/local/squid/logs/headers.log", MAX_URL << 1, 0); assert(NULL != headerslog); #endif #if FORW_VIA_DB fvdbInit(); #endif #if MULTICAST_MISS_STREAM if (Config.mcast_miss.addr.s_addr != no_addr.s_addr) { memset(&mcast_miss_to, '\0', sizeof(mcast_miss_to)); mcast_miss_to.sin_family = AF_INET; mcast_miss_to.sin_port = htons(Config.mcast_miss.port); mcast_miss_to.sin_addr.s_addr = Config.mcast_miss.addr.s_addr; mcast_miss_fd = comm_open(SOCK_DGRAM, IPPROTO_UDP, Config.Addrs.udp_incoming, Config.mcast_miss.port, COMM_NONBLOCKING, "Multicast Miss Stream"); if (mcast_miss_fd < 0) fatal("Cannot open Multicast Miss Stream Socket"); debug(46, 1) ("Multicast Miss Stream Socket opened on FD %d\n", mcast_miss_fd); mcastSetTtl(mcast_miss_fd, Config.mcast_miss.ttl); if (strlen(Config.mcast_miss.encode_key) < 16) fatal("mcast_encode_key is too short, must be 16 characters"); } #endif } const char * accessLogTime(time_t t) { struct tm *tm; static char buf[128]; static time_t last_t = 0; if (t != last_t) { tm = localtime(&t); strftime(buf, 127, "%Y/%m/%d %H:%M:%S", tm); last_t = t; } return buf; } #if FORW_VIA_DB static void fvdbInit(void) { via_table = hash_create((HASHCMP *) strcmp, 977, hash4); forw_table = hash_create((HASHCMP *) strcmp, 977, hash4); cachemgrRegister("via_headers", "Via Request Headers", fvdbDumpVia, 0, 1); cachemgrRegister("forw_headers", "X-Forwarded-For Request Headers", fvdbDumpForw, 0, 1); } static void fvdbCount(hash_table * hash, const char *key) { fvdb_entry *fv; if (NULL == hash) return; fv = hash_lookup(hash, key); if (NULL == fv) { fv = xcalloc(1, sizeof(fvdb_entry)); fv->hash.key = xstrdup(key); hash_join(hash, &fv->hash); } fv->n++; } void fvdbCountVia(const char *key) { fvdbCount(via_table, key); } void fvdbCountForw(const char *key) { fvdbCount(forw_table, key); } static void fvdbDumpTable(StoreEntry * e, hash_table * hash) { hash_link *h; fvdb_entry *fv; if (hash == NULL) return; hash_first(hash); while ((h = hash_next(hash))) { fv = (fvdb_entry *) h; storeAppendPrintf(e, "%9d %s\n", fv->n, hashKeyStr(&fv->hash)); } } static void fvdbDumpVia(StoreEntry * e) { fvdbDumpTable(e, via_table); } static void fvdbDumpForw(StoreEntry * e) { fvdbDumpTable(e, forw_table); } static void fvdbFreeEntry(void *data) { fvdb_entry *fv = data; xfree(fv->hash.key); xfree(fv); } static void fvdbClear(void) { hashFreeItems(via_table, fvdbFreeEntry); hashFreeMemory(via_table); via_table = hash_create((HASHCMP *) strcmp, 977, hash4); hashFreeItems(forw_table, fvdbFreeEntry); hashFreeMemory(forw_table); forw_table = hash_create((HASHCMP *) strcmp, 977, hash4); } #endif #if MULTICAST_MISS_STREAM /* * From http://www.io.com/~paulhart/game/algorithms/tea.html * * size of 'ibuf' must be a multiple of 2. * size of 'key' must be 4. * 'ibuf' is modified in place, encrypted data is written in * network byte order. */ static void mcast_encode(unsigned int *ibuf, size_t isize, const unsigned int *key) { unsigned int y; unsigned int z; unsigned int sum; const unsigned int delta = 0x9e3779b9; unsigned int n = 32; const unsigned int k0 = htonl(key[0]); const unsigned int k1 = htonl(key[1]); const unsigned int k2 = htonl(key[2]); const unsigned int k3 = htonl(key[3]); int i; for (i = 0; i < isize; i += 2) { y = htonl(ibuf[i]); z = htonl(ibuf[i + 1]); sum = 0; for (n = 32; n; n--) { sum += delta; y += (z << 4) + (k0 ^ z) + (sum ^ (z >> 5)) + k1; z += (y << 4) + (k2 ^ y) + (sum ^ (y >> 5)) + k3; } ibuf[i] = htonl(y); ibuf[i + 1] = htonl(z); } } #endif #if HEADERS_LOG void headersLog(int cs, int pq, method_t m, void *data) { HttpReply *rep; request_t *req; unsigned short magic = 0; unsigned char M = (unsigned char) m; unsigned short S; char *hmask; int ccmask = 0; if (0 == pq) { /* reply */ rep = data; req = NULL; magic = 0x0050; hmask = rep->header.mask; if (rep->cache_control) ccmask = rep->cache_control->mask; } else { /* request */ req = data; rep = NULL; magic = 0x0051; hmask = req->header.mask; if (req->cache_control) ccmask = req->cache_control->mask; } if (0 == cs) { /* client */ magic |= 0x4300; } else { /* server */ magic |= 0x5300; } magic = htons(magic); ccmask = htonl(ccmask); if (0 == pq) S = (unsigned short) rep->sline.status; else S = (unsigned short) HTTP_STATUS_NONE; logfileWrite(headerslog, &magic, sizeof(magic)); logfileWrite(headerslog, &M, sizeof(M)); logfileWrite(headerslog, &S, sizeof(S)); logfileWrite(headerslog, hmask, sizeof(HttpHeaderMask)); logfileWrite(headerslog, &ccmask, sizeof(int)); } #endif