src/log/access_log.cc

   1 /*
   2  * DEBUG: section 46    Access Log
   3  * AUTHOR: Duane Wessels
   4  *
   5  * SQUID Web Proxy Cache          http://www.squid-cache.org/
   6  * ----------------------------------------------------------
   7  *
   8  *  Squid is the result of efforts by numerous individuals from
   9  *  the Internet community; see the CONTRIBUTORS file for full
  10  *  details.   Many organizations have provided support for Squid's
  11  *  development; see the SPONSORS file for full details.  Squid is
  12  *  Copyrighted (C) 2001 by the Regents of the University of
  13  *  California; see the COPYRIGHT file for full details.  Squid
  14  *  incorporates software developed and/or copyrighted by other
  15  *  sources; see the CREDITS file for full details.
  16  *
  17  *  This program is free software; you can redistribute it and/or modify
  18  *  it under the terms of the GNU General Public License as published by
  19  *  the Free Software Foundation; either version 2 of the License, or
  20  *  (at your option) any later version.
  21  *
  22  *  This program is distributed in the hope that it will be useful,
  23  *  but WITHOUT ANY WARRANTY; without even the implied warranty of
  24  *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  25  *  GNU General Public License for more details.
  26  *
  27  *  You should have received a copy of the GNU General Public License
  28  *  along with this program; if not, write to the Free Software
  29  *  Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111, USA.
  30  *
  31  */
  32
  33 #include "squid.h"
  34 #include "AccessLogEntry.h"
  35 #include "acl/Checklist.h"
  36 #if USE_ADAPTATION
  37 #include "adaptation/Config.h"
  38 #endif
  39 #include "CachePeer.h"
  40 #include "err_detail_type.h"
  41 #include "errorpage.h"
  42 #include "errorpage.h"
  43 #include "errorpage.h"
  44 #include "format/Token.h"
  45 #include "globals.h"
  46 #include "hier_code.h"
  47 #include "HttpReply.h"
  48 #include "HttpRequest.h"
  49 #include "log/access_log.h"
  50 #include "log/Config.h"
  51 #include "log/CustomLog.h"
  52 #include "log/File.h"
  53 #include "log/Formats.h"
  54 #include "MemBuf.h"
  55 #include "mgr/Registration.h"
  56 #include "rfc1738.h"
  57 #include "SquidConfig.h"
  58 #include "SquidTime.h"
  59 #include "Store.h"
  60
  61 #if USE_SQUID_EUI
  62 #include "eui/Eui48.h"
  63 #include "eui/Eui64.h"
  64 #endif
  65
  66 #if HEADERS_LOG
  67 static Logfile *headerslog = NULL;
  68 #endif
  69
  70 #if MULTICAST_MISS_STREAM
  71 static int mcast_miss_fd = -1;
  72
  73 static struct sockaddr_in mcast_miss_to;
  74 static void mcast_encode(unsigned int *, size_t, const unsigned int *);
  75 #endif
  76
  77 #if USE_FORW_VIA_DB
  78
  79 typedef struct {
  80     hash_link hash;
  81     int n;
  82 } fvdb_entry;
  83 static hash_table *via_table = NULL;
  84 static hash_table *forw_table = NULL;
  85 static void fvdbInit();
  86 static void fvdbDumpTable(StoreEntry * e, hash_table * hash);
  87 static void fvdbCount(hash_table * hash, const char *key);
  88 static OBJH fvdbDumpVia;
  89 static OBJH fvdbDumpForw;
  90 static FREE fvdbFreeEntry;
  91 static void fvdbClear(void);
  92 static void fvdbRegisterWithCacheManager();
  93 #endif
  94
  95 int LogfileStatus = LOG_DISABLE;
  96
  97 void
  98 accessLogLogTo(CustomLog* log, AccessLogEntry::Pointer &al, ACLChecklist * checklist)
  99 {
 100
 101     if (al->url == NULL)
 102         al->url = dash_str;
 103
 104     if (!al->http.content_type || *al->http.content_type == '\0')
 105         al->http.content_type = dash_str;
 106
 107     if (al->icp.opcode)
 108         al->_private.method_str = icp_opcode_str[al->icp.opcode];
 109     else if (al->htcp.opcode)
 110         al->_private.method_str = al->htcp.opcode;
 111     else
 112         al->_private.method_str = NULL;
 113
 114     if (al->hier.host[0] == '\0')
 115         xstrncpy(al->hier.host, dash_str, SQUIDHOSTNAMELEN);
 116
 117     for (; log; log = log->next) {
 118         if (log->aclList && checklist && checklist->fastCheck(log->aclList) != ACCESS_ALLOWED)
 119             continue;
 120
 121         if (log->logfile) {
 122             logfileLineStart(log->logfile);
 123
 124             switch (log->type) {
 125
 126             case Log::Format::CLF_SQUID:
 127                 Log::Format::SquidNative(al, log->logfile);
 128                 break;
 129
 130             case Log::Format::CLF_COMBINED:
 131                 Log::Format::HttpdCombined(al, log->logfile);
 132                 break;
 133
 134             case Log::Format::CLF_COMMON:
 135                 Log::Format::HttpdCommon(al, log->logfile);
 136                 break;
 137
 138             case Log::Format::CLF_REFERER:
 139                 Log::Format::SquidReferer(al, log->logfile);
 140                 break;
 141
 142             case Log::Format::CLF_USERAGENT:
 143                 Log::Format::SquidUserAgent(al, log->logfile);
 144                 break;
 145
 146             case Log::Format::CLF_CUSTOM:
 147                 Log::Format::SquidCustom(al, log);
 148                 break;
 149
 150 #if ICAP_CLIENT
 151             case Log::Format::CLF_ICAP_SQUID:
 152                 Log::Format::SquidIcap(al, log->logfile);
 153                 break;
 154 #endif
 155
 156             case Log::Format::CLF_NONE:
 157                 return; // abort!
 158
 159             default:
 160                 fatalf("Unknown log format %d\n", log->type);
 161                 break;
 162             }
 163
 164             logfileLineEnd(log->logfile);
 165         }
 166
 167         // NP:  WTF?  if _any_ log line has no checklist ignore the following ones?
 168         if (!checklist)
 169             break;
 170     }
 171 }
 172
 173 void
 174 accessLogLog(AccessLogEntry::Pointer &al, ACLChecklist * checklist)
 175 {
 176     if (LogfileStatus != LOG_ENABLE)
 177         return;
 178
 179     accessLogLogTo(Config.Log.accesslogs, al, checklist);
 180 #if MULTICAST_MISS_STREAM
 181
 182     if (al->cache.code != LOG_TCP_MISS)
 183         (void) 0;
 184     else if (al->http.method != METHOD_GET)
 185         (void) 0;
 186     else if (mcast_miss_fd < 0)
 187         (void) 0;
 188     else {
 189         unsigned int ibuf[365];
 190         size_t isize;
 191         xstrncpy((char *) ibuf, al->url, 364 * sizeof(int));
 192         isize = ((strlen(al->url) + 8) / 8) * 2;
 193
 194         if (isize > 364)
 195             isize = 364;
 196
 197         mcast_encode((unsigned int *) ibuf, isize,
 198                      (const unsigned int *) Config.mcast_miss.encode_key);
 199
 200         comm_udp_sendto(mcast_miss_fd,
 201                         &mcast_miss_to, sizeof(mcast_miss_to),
 202                         ibuf, isize * sizeof(int));
 203     }
 204
 205 #endif
 206 }
 207
 208 void
 209 accessLogRotate(void)
 210 {
 211     CustomLog *log;
 212 #if USE_FORW_VIA_DB
 213
 214     fvdbClear();
 215 #endif
 216
 217     for (log = Config.Log.accesslogs; log; log = log->next) {
 218         if (log->logfile) {
 219             logfileRotate(log->logfile);
 220         }
 221     }
 222
 223 #if HEADERS_LOG
 224
 225     logfileRotate(headerslog);
 226
 227 #endif
 228 }
 229
 230 void
 231 accessLogClose(void)
 232 {
 233     CustomLog *log;
 234
 235     for (log = Config.Log.accesslogs; log; log = log->next) {
 236         if (log->logfile) {
 237             logfileClose(log->logfile);
 238             log->logfile = NULL;
 239         }
 240     }
 241
 242 #if HEADERS_LOG
 243
 244     logfileClose(headerslog);
 245
 246     headerslog = NULL;
 247
 248 #endif
 249 }
 250
 251 HierarchyLogEntry::HierarchyLogEntry() :
 252         code(HIER_NONE),
 253         cd_lookup(LOOKUP_NONE),
 254         n_choices(0),
 255         n_ichoices(0),
 256         peer_reply_status(Http::scNone),
 257         peer_response_time(-1),
 258         total_response_time(-1),
 259         tcpServer(NULL),
 260         bodyBytesRead(-1)
 261 {
 262     memset(host, '\0', SQUIDHOSTNAMELEN);
 263     memset(cd_host, '\0', SQUIDHOSTNAMELEN);
 264
 265     peer_select_start.tv_sec =0;
 266     peer_select_start.tv_usec =0;
 267
 268     store_complete_stop.tv_sec =0;
 269     store_complete_stop.tv_usec =0;
 270
 271     peer_http_request_sent.tv_sec = 0;
 272     peer_http_request_sent.tv_usec = 0;
 273
 274     first_conn_start.tv_sec = 0;
 275     first_conn_start.tv_usec = 0;
 276 }
 277
 278 void
 279 HierarchyLogEntry::note(const Comm::ConnectionPointer &server, const char *requestedHost)
 280 {
 281     tcpServer = server;
 282     if (tcpServer == NULL) {
 283         code = HIER_NONE;
 284         xstrncpy(host, requestedHost, sizeof(host));
 285     } else {
 286         code = tcpServer->peerType;
 287
 288         if (tcpServer->getPeer()) {
 289             // went to peer, log peer host name
 290             xstrncpy(host, tcpServer->getPeer()->name, sizeof(host));
 291         } else {
 292             xstrncpy(host, requestedHost, sizeof(host));
 293         }
 294     }
 295 }
 296
 297 static void
 298 accessLogRegisterWithCacheManager(void)
 299 {
 300 #if USE_FORW_VIA_DB
 301     fvdbRegisterWithCacheManager();
 302 #endif
 303 }
 304
 305 void
 306 accessLogInit(void)
 307 {
 308     CustomLog *log;
 309
 310     accessLogRegisterWithCacheManager();
 311
 312 #if USE_ADAPTATION
 313     Log::TheConfig.hasAdaptToken = false;
 314 #endif
 315 #if ICAP_CLIENT
 316     Log::TheConfig.hasIcapToken = false;
 317 #endif
 318
 319     for (log = Config.Log.accesslogs; log; log = log->next) {
 320         if (log->type == Log::Format::CLF_NONE)
 321             continue;
 322
 323         log->logfile = logfileOpen(log->filename, log->bufferSize, log->fatal);
 324
 325         LogfileStatus = LOG_ENABLE;
 326
 327 #if USE_ADAPTATION
 328         for (Format::Token * curr_token = (log->logFormat?log->logFormat->format:NULL); curr_token; curr_token = curr_token->next) {
 329             if (curr_token->type == Format::LFT_ADAPTATION_SUM_XACT_TIMES ||
 330                     curr_token->type == Format::LFT_ADAPTATION_ALL_XACT_TIMES ||
 331                     curr_token->type == Format::LFT_ADAPTATION_LAST_HEADER ||
 332                     curr_token->type == Format::LFT_ADAPTATION_LAST_HEADER_ELEM ||
 333                     curr_token->type == Format::LFT_ADAPTATION_LAST_ALL_HEADERS||
 334                     (curr_token->type == Format::LFT_NOTE && !Adaptation::Config::metaHeaders.empty())) {
 335                 Log::TheConfig.hasAdaptToken = true;
 336             }
 337 #if ICAP_CLIENT
 338             if (curr_token->type == Format::LFT_ICAP_TOTAL_TIME) {
 339                 Log::TheConfig.hasIcapToken = true;
 340             }
 341 #endif
 342         }
 343 #endif
 344     }
 345
 346 #if HEADERS_LOG
 347
 348     headerslog = logfileOpen("/usr/local/squid/logs/headers.log", 512);
 349
 350     assert(NULL != headerslog);
 351
 352 #endif
 353 #if MULTICAST_MISS_STREAM
 354
 355     if (Config.mcast_miss.addr.s_addr != no_addr.s_addr) {
 356         memset(&mcast_miss_to, '\0', sizeof(mcast_miss_to));
 357         mcast_miss_to.sin_family = AF_INET;
 358         mcast_miss_to.sin_port = htons(Config.mcast_miss.port);
 359         mcast_miss_to.sin_addr.s_addr = Config.mcast_miss.addr.s_addr;
 360         mcast_miss_fd = comm_open(SOCK_DGRAM,
 361                                   IPPROTO_UDP,
 362                                   Config.Addrs.udp_incoming,
 363                                   Config.mcast_miss.port,
 364                                   COMM_NONBLOCKING,
 365                                   "Multicast Miss Stream");
 366
 367         if (mcast_miss_fd < 0)
 368             fatal("Cannot open Multicast Miss Stream Socket");
 369
 370         debugs(46, DBG_IMPORTANT, "Multicast Miss Stream Socket opened on FD " << mcast_miss_fd);
 371
 372         mcastSetTtl(mcast_miss_fd, Config.mcast_miss.ttl);
 373
 374         if (strlen(Config.mcast_miss.encode_key) < 16)
 375             fatal("mcast_encode_key is too short, must be 16 characters");
 376     }
 377
 378 #endif
 379 #if USE_FORW_VIA_DB
 380
 381     fvdbInit();
 382
 383 #endif
 384 }
 385
 386 #if USE_FORW_VIA_DB
 387
 388 static void
 389 fvdbInit(void)
 390 {
 391     via_table = hash_create((HASHCMP *) strcmp, 977, hash4);
 392     forw_table = hash_create((HASHCMP *) strcmp, 977, hash4);
 393 }
 394
 395 static void
 396 fvdbRegisterWithCacheManager(void)
 397 {
 398     Mgr::RegisterAction("via_headers", "Via Request Headers", fvdbDumpVia, 0, 1);
 399     Mgr::RegisterAction("forw_headers", "X-Forwarded-For Request Headers",
 400                         fvdbDumpForw, 0, 1);
 401 }
 402
 403 static void
 404 fvdbCount(hash_table * hash, const char *key)
 405 {
 406     fvdb_entry *fv;
 407
 408     if (NULL == hash)
 409         return;
 410
 411     fv = (fvdb_entry *)hash_lookup(hash, key);
 412
 413     if (NULL == fv) {
 414         fv = static_cast <fvdb_entry *>(xcalloc(1, sizeof(fvdb_entry)));
 415         fv->hash.key = xstrdup(key);
 416         hash_join(hash, &fv->hash);
 417     }
 418
 419     ++ fv->n;
 420 }
 421
 422 void
 423 fvdbCountVia(const char *key)
 424 {
 425     fvdbCount(via_table, key);
 426 }
 427
 428 void
 429 fvdbCountForw(const char *key)
 430 {
 431     fvdbCount(forw_table, key);
 432 }
 433
 434 static void
 435 fvdbDumpTable(StoreEntry * e, hash_table * hash)
 436 {
 437     hash_link *h;
 438     fvdb_entry *fv;
 439
 440     if (hash == NULL)
 441         return;
 442
 443     hash_first(hash);
 444
 445     while ((h = hash_next(hash))) {
 446         fv = (fvdb_entry *) h;
 447         storeAppendPrintf(e, "%9d %s\n", fv->n, hashKeyStr(&fv->hash));
 448     }
 449 }
 450
 451 static void
 452 fvdbDumpVia(StoreEntry * e)
 453 {
 454     fvdbDumpTable(e, via_table);
 455 }
 456
 457 static void
 458 fvdbDumpForw(StoreEntry * e)
 459 {
 460     fvdbDumpTable(e, forw_table);
 461 }
 462
 463 static
 464 void
 465 fvdbFreeEntry(void *data)
 466 {
 467     fvdb_entry *fv = static_cast <fvdb_entry *>(data);
 468     xfree(fv->hash.key);
 469     xfree(fv);
 470 }
 471
 472 static void
 473 fvdbClear(void)
 474 {
 475     hashFreeItems(via_table, fvdbFreeEntry);
 476     hashFreeMemory(via_table);
 477     via_table = hash_create((HASHCMP *) strcmp, 977, hash4);
 478     hashFreeItems(forw_table, fvdbFreeEntry);
 479     hashFreeMemory(forw_table);
 480     forw_table = hash_create((HASHCMP *) strcmp, 977, hash4);
 481 }
 482
 483 #endif
 484
 485 #if MULTICAST_MISS_STREAM
 486 /*
 487  * From http://www.io.com/~paulhart/game/algorithms/tea.html
 488  *
 489  * size of 'ibuf' must be a multiple of 2.
 490  * size of 'key' must be 4.
 491  * 'ibuf' is modified in place, encrypted data is written in
 492  * network byte order.
 493  */
 494 static void
 495 mcast_encode(unsigned int *ibuf, size_t isize, const unsigned int *key)
 496 {
 497     unsigned int y;
 498     unsigned int z;
 499     unsigned int sum;
 500     const unsigned int delta = 0x9e3779b9;
 501     unsigned int n = 32;
 502     const unsigned int k0 = htonl(key[0]);
 503     const unsigned int k1 = htonl(key[1]);
 504     const unsigned int k2 = htonl(key[2]);
 505     const unsigned int k3 = htonl(key[3]);
 506     int i;
 507
 508     for (i = 0; i < isize; i += 2) {
 509         y = htonl(ibuf[i]);
 510         z = htonl(ibuf[i + 1]);
 511         sum = 0;
 512
 513         for (n = 32; n; --n) {
 514             sum += delta;
 515             y += (z << 4) + (k0 ^ z) + (sum ^ (z >> 5)) + k1;
 516             z += (y << 4) + (k2 ^ y) + (sum ^ (y >> 5)) + k3;
 517         }
 518
 519         ibuf[i] = htonl(y);
 520         ibuf[i + 1] = htonl(z);
 521     }
 522 }
 523
 524 #endif
 525
 526 #if HEADERS_LOG
 527 void
 528 headersLog(int cs, int pq, const HttpRequestMethod& method, void *data)
 529 {
 530     HttpReply *rep;
 531     HttpRequest *req;
 532     unsigned short magic = 0;
 533     unsigned char M = (unsigned char) m;
 534     char *hmask;
 535     int ccmask = 0;
 536
 537     if (0 == pq) {
 538         /* reply */
 539         rep = data;
 540         req = NULL;
 541         magic = 0x0050;
 542         hmask = rep->header.mask;
 543
 544         if (rep->cache_control)
 545             ccmask = rep->cache_control->mask;
 546     } else {
 547         /* request */
 548         req = data;
 549         rep = NULL;
 550         magic = 0x0051;
 551         hmask = req->header.mask;
 552
 553         if (req->cache_control)
 554             ccmask = req->cache_control->mask;
 555     }
 556
 557     if (0 == cs) {
 558         /* client */
 559         magic |= 0x4300;
 560     } else {
 561         /* server */
 562         magic |= 0x5300;
 563     }
 564
 565     magic = htons(magic);
 566     ccmask = htonl(ccmask);
 567
 568     unsigned short S = 0;
 569     if (0 == pq)
 570         S = static_cast<unsigned short>(rep->sline.status());
 571
 572     logfileWrite(headerslog, &magic, sizeof(magic));
 573     logfileWrite(headerslog, &M, sizeof(M));
 574     logfileWrite(headerslog, &S, sizeof(S));
 575     logfileWrite(headerslog, hmask, sizeof(HttpHeaderMask));
 576     logfileWrite(headerslog, &ccmask, sizeof(int));
 577 }
 578
 579 #endif