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