src/log/access_log.cc

   1 /*
   2  * $Id$
   3  *
   4  * DEBUG: section 46    Access Log
   5  * AUTHOR: Duane Wessels
   6  *
   7  * SQUID Web Proxy Cache          http://www.squid-cache.org/
   8  * ----------------------------------------------------------
   9  *
  10  *  Squid is the result of efforts by numerous individuals from
  11  *  the Internet community; see the CONTRIBUTORS file for full
  12  *  details.   Many organizations have provided support for Squid's
  13  *  development; see the SPONSORS file for full details.  Squid is
  14  *  Copyrighted (C) 2001 by the Regents of the University of
  15  *  California; see the COPYRIGHT file for full details.  Squid
  16  *  incorporates software developed and/or copyrighted by other
  17  *  sources; see the CREDITS file for full details.
  18  *
  19  *  This program is free software; you can redistribute it and/or modify
  20  *  it under the terms of the GNU General Public License as published by
  21  *  the Free Software Foundation; either version 2 of the License, or
  22  *  (at your option) any later version.
  23  *
  24  *  This program is distributed in the hope that it will be useful,
  25  *  but WITHOUT ANY WARRANTY; without even the implied warranty of
  26  *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  27  *  GNU General Public License for more details.
  28  *
  29  *  You should have received a copy of the GNU General Public License
  30  *  along with this program; if not, write to the Free Software
  31  *  Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111, USA.
  32  *
  33  */
  34
  35
  36 #include "squid.h"
  37 #include "AccessLogEntry.h"
  38
  39 // Store.h Required by configuration directives parsing/dumping only
  40 #include "Store.h"
  41
  42 #include "errorpage.h"
  43 #include "err_detail_type.h"
  44 #include "acl/Checklist.h"
  45 #include "errorpage.h"
  46 #if USE_SQUID_EUI
  47 #include "eui/Eui48.h"
  48 #include "eui/Eui64.h"
  49 #endif
  50 #include "hier_code.h"
  51 #include "HttpReply.h"
  52 #include "HttpRequest.h"
  53 #include "log/File.h"
  54 #include "MemBuf.h"
  55 #include "mgr/Registration.h"
  56 #include "rfc1738.h"
  57 #include "SquidTime.h"
  58
  59 static void accessLogSquid(AccessLogEntry * al, Logfile * logfile);
  60 static void accessLogCommon(AccessLogEntry * al, Logfile * logfile);
  61 static void accessLogCustom(AccessLogEntry * al, customlog * log);
  62 #if HEADERS_LOG
  63 static Logfile *headerslog = NULL;
  64 #endif
  65
  66 #if MULTICAST_MISS_STREAM
  67 static int mcast_miss_fd = -1;
  68
  69 static struct sockaddr_in mcast_miss_to;
  70 static void mcast_encode(unsigned int *, size_t, const unsigned int *);
  71 #endif
  72
  73 const char *log_tags[] = {
  74     "NONE",
  75     "TCP_HIT",
  76     "TCP_MISS",
  77     "TCP_REFRESH_UNMODIFIED",
  78     "TCP_REFRESH_FAIL", // same tag logged for LOG_TCP_REFRESH_FAIL_OLD and
  79     "TCP_REFRESH_FAIL", // LOG_TCP_REFRESH_FAIL_ERR for backward-compatibility
  80     "TCP_REFRESH_MODIFIED",
  81     "TCP_CLIENT_REFRESH_MISS",
  82     "TCP_IMS_HIT",
  83     "TCP_SWAPFAIL_MISS",
  84     "TCP_NEGATIVE_HIT",
  85     "TCP_MEM_HIT",
  86     "TCP_DENIED",
  87     "TCP_DENIED_REPLY",
  88     "TCP_OFFLINE_HIT",
  89 #if LOG_TCP_REDIRECTS
  90     "TCP_REDIRECT",
  91 #endif
  92     "UDP_HIT",
  93     "UDP_MISS",
  94     "UDP_DENIED",
  95     "UDP_INVALID",
  96     "UDP_MISS_NOFETCH",
  97     "ICP_QUERY",
  98     "LOG_TYPE_MAX"
  99 };
 100
 101 #if USE_FORW_VIA_DB
 102
 103 typedef struct {
 104     hash_link hash;
 105     int n;
 106 } fvdb_entry;
 107 static hash_table *via_table = NULL;
 108 static hash_table *forw_table = NULL;
 109 static void fvdbInit();
 110 static void fvdbDumpTable(StoreEntry * e, hash_table * hash);
 111 static void fvdbCount(hash_table * hash, const char *key);
 112 static OBJH fvdbDumpVia;
 113 static OBJH fvdbDumpForw;
 114 static FREE fvdbFreeEntry;
 115 static void fvdbClear(void);
 116 static void fvdbRegisterWithCacheManager();
 117 #endif
 118
 119 int LogfileStatus = LOG_DISABLE;
 120
 121 #if USE_ADAPTATION
 122 bool alLogformatHasAdaptToken = false;
 123 #endif
 124
 125 #if ICAP_CLIENT
 126 bool alLogformatHasIcapToken = false;
 127 #endif
 128
 129 #define LOG_BUF_SZ (MAX_URL<<2)
 130
 131 static const char c2x[] =
 132     "000102030405060708090a0b0c0d0e0f"
 133     "101112131415161718191a1b1c1d1e1f"
 134     "202122232425262728292a2b2c2d2e2f"
 135     "303132333435363738393a3b3c3d3e3f"
 136     "404142434445464748494a4b4c4d4e4f"
 137     "505152535455565758595a5b5c5d5e5f"
 138     "606162636465666768696a6b6c6d6e6f"
 139     "707172737475767778797a7b7c7d7e7f"
 140     "808182838485868788898a8b8c8d8e8f"
 141     "909192939495969798999a9b9c9d9e9f"
 142     "a0a1a2a3a4a5a6a7a8a9aaabacadaeaf"
 143     "b0b1b2b3b4b5b6b7b8b9babbbcbdbebf"
 144     "c0c1c2c3c4c5c6c7c8c9cacbcccdcecf"
 145     "d0d1d2d3d4d5d6d7d8d9dadbdcdddedf"
 146     "e0e1e2e3e4e5e6e7e8e9eaebecedeeef"
 147     "f0f1f2f3f4f5f6f7f8f9fafbfcfdfeff";
 148
 149 /* log_quote -- URL-style encoding on MIME headers. */
 150
 151 char *
 152 log_quote(const char *header)
 153 {
 154     int c;
 155     int i;
 156     char *buf;
 157     char *buf_cursor;
 158
 159     if (header == NULL) {
 160         buf = static_cast<char *>(xcalloc(1, 1));
 161         *buf = '\0';
 162         return buf;
 163     }
 164
 165     buf = static_cast<char *>(xcalloc(1, (strlen(header) * 3) + 1));
 166     buf_cursor = buf;
 167     /*
 168      * We escape: \x00-\x1F"#%;<>?{}|\\\\^~`\[\]\x7F-\xFF
 169      * which is the default escape list for the CPAN Perl5 URI module
 170      * modulo the inclusion of space (x40) to make the raw logs a bit
 171      * more readable.
 172      */
 173
 174     while ((c = *(const unsigned char *) header++) != '\0') {
 175 #if !OLD_LOG_MIME
 176
 177         if (c == '\r') {
 178             *buf_cursor++ = '\\';
 179             *buf_cursor++ = 'r';
 180         } else if (c == '\n') {
 181             *buf_cursor++ = '\\';
 182             *buf_cursor++ = 'n';
 183         } else
 184 #endif
 185             if (c <= 0x1F
 186                     || c >= 0x7F
 187                     || c == '%'
 188 #if OLD_LOG_MIME
 189                     || c == '"'
 190                     || c == '#'
 191                     || c == ';'
 192                     || c == '<'
 193                     || c == '>'
 194                     || c == '?'
 195                     || c == '{'
 196                     || c == '}'
 197                     || c == '|'
 198                     || c == '\\'
 199                     || c == '^'
 200                     || c == '~'
 201                     || c == '`'
 202 #endif
 203                     || c == '['
 204                     || c == ']') {
 205                 *buf_cursor++ = '%';
 206                 i = c * 2;
 207                 *buf_cursor++ = c2x[i];
 208                 *buf_cursor++ = c2x[i + 1];
 209 #if !OLD_LOG_MIME
 210
 211             } else if (c == '\\') {
 212                 *buf_cursor++ = '\\';
 213                 *buf_cursor++ = '\\';
 214 #endif
 215
 216             } else {
 217                 *buf_cursor++ = (char) c;
 218             }
 219     }
 220
 221     *buf_cursor = '\0';
 222     return buf;
 223 }
 224
 225 static char *
 226 username_quote(const char *header)
 227 /* copy of log_quote. Bugs there will be found here */
 228 {
 229     int c;
 230     int i;
 231     char *buf;
 232     char *buf_cursor;
 233
 234     if (header == NULL) {
 235         buf = static_cast<char *>(xcalloc(1, 1));
 236         *buf = '\0';
 237         return buf;
 238     }
 239
 240     buf = static_cast<char *>(xcalloc(1, (strlen(header) * 3) + 1));
 241     buf_cursor = buf;
 242     /*
 243      * We escape: space \x00-\x1F and space (0x40) and \x7F-\xFF
 244      * to prevent garbage in the logs. CR and LF are also there just in case.
 245      */
 246
 247     while ((c = *(const unsigned char *) header++) != '\0') {
 248         if (c == '\r') {
 249             *buf_cursor++ = '\\';
 250             *buf_cursor++ = 'r';
 251         } else if (c == '\n') {
 252             *buf_cursor++ = '\\';
 253             *buf_cursor++ = 'n';
 254         } else if (c <= 0x1F
 255                    || c >= 0x7F
 256                    || c == '%'
 257                    || c == ' ') {
 258             *buf_cursor++ = '%';
 259             i = c * 2;
 260             *buf_cursor++ = c2x[i];
 261             *buf_cursor++ = c2x[i + 1];
 262         } else {
 263             *buf_cursor++ = (char) c;
 264         }
 265     }
 266
 267     *buf_cursor = '\0';
 268     return buf;
 269 }
 270
 271 static char *
 272 accessLogFormatName(const char *name)
 273 {
 274     if (NULL == name)
 275         return NULL;
 276
 277     if (name[0] == '\0')
 278         return NULL;
 279
 280     return username_quote(name);
 281 }
 282
 283 static char *
 284 log_quoted_string(const char *str)
 285 {
 286     char *out = (char *)xmalloc(strlen(str) * 2 + 1);
 287     char *p = out;
 288
 289     while (*str) {
 290         int l = strcspn(str, "\"\\\r\n\t");
 291         memcpy(p, str, l);
 292         str += l;
 293         p += l;
 294
 295         switch (*str) {
 296
 297         case '\0':
 298             break;
 299
 300         case '\r':
 301             *p++ = '\\';
 302             *p++ = 'r';
 303             str++;
 304             break;
 305
 306         case '\n':
 307             *p++ = '\\';
 308             *p++ = 'n';
 309             str++;
 310             break;
 311
 312         case '\t':
 313             *p++ = '\\';
 314             *p++ = 't';
 315             str++;
 316             break;
 317
 318         default:
 319             *p++ = '\\';
 320             *p++ = *str;
 321             str++;
 322             break;
 323         }
 324     }
 325
 326     *p++ = '\0';
 327     return out;
 328 }
 329
 330 /*
 331  * Bytecodes for the configureable logformat stuff
 332  */
 333 typedef enum {
 334     LFT_NONE,                   /* dummy */
 335     LFT_STRING,
 336
 337     LFT_CLIENT_IP_ADDRESS,
 338     LFT_CLIENT_FQDN,
 339     LFT_CLIENT_PORT,
 340 #if USE_SQUID_EUI
 341     LFT_CLIENT_EUI,
 342 #endif
 343
 344     /*LFT_SERVER_IP_ADDRESS, */
 345     LFT_SERVER_IP_OR_PEER_NAME,
 346     /*LFT_SERVER_PORT, */
 347
 348     LFT_LOCAL_IP,
 349     LFT_LOCAL_PORT,
 350     /*LFT_LOCAL_NAME, */
 351     LFT_PEER_LOCAL_PORT,
 352
 353     LFT_TIME_SECONDS_SINCE_EPOCH,
 354     LFT_TIME_SUBSECOND,
 355     LFT_TIME_LOCALTIME,
 356     LFT_TIME_GMT,
 357     LFT_TIME_TO_HANDLE_REQUEST,
 358
 359     LFT_PEER_RESPONSE_TIME,
 360     LFT_TOTAL_SERVER_SIDE_RESPONSE_TIME,
 361     LFT_DNS_WAIT_TIME,
 362
 363     LFT_REQUEST_HEADER,
 364     LFT_REQUEST_HEADER_ELEM,
 365     LFT_REQUEST_ALL_HEADERS,
 366
 367     LFT_ADAPTED_REQUEST_HEADER,
 368     LFT_ADAPTED_REQUEST_HEADER_ELEM,
 369     LFT_ADAPTED_REQUEST_ALL_HEADERS,
 370
 371     LFT_REPLY_HEADER,
 372     LFT_REPLY_HEADER_ELEM,
 373     LFT_REPLY_ALL_HEADERS,
 374
 375     LFT_USER_NAME,
 376     LFT_USER_LOGIN,
 377     LFT_USER_IDENT,
 378     /*LFT_USER_REALM, */
 379     /*LFT_USER_SCHEME, */
 380     LFT_USER_EXTERNAL,
 381
 382     LFT_HTTP_SENT_STATUS_CODE_OLD_30,
 383     LFT_HTTP_SENT_STATUS_CODE,
 384     LFT_HTTP_RECEIVED_STATUS_CODE,
 385     /*LFT_HTTP_STATUS, */
 386     LFT_HTTP_BODY_BYTES_READ,
 387
 388     LFT_SQUID_STATUS,
 389     LFT_SQUID_ERROR,
 390     LFT_SQUID_ERROR_DETAIL,
 391     LFT_SQUID_HIERARCHY,
 392
 393     LFT_MIME_TYPE,
 394
 395     LFT_REQUEST_METHOD,
 396     LFT_REQUEST_URI,
 397     LFT_REQUEST_URLPATH,
 398     /*LFT_REQUEST_QUERY, * // * this is not needed. see strip_query_terms */
 399     LFT_REQUEST_VERSION,
 400
 401     LFT_REQUEST_SIZE_TOTAL,
 402     /*LFT_REQUEST_SIZE_LINE, */
 403     LFT_REQUEST_SIZE_HEADERS,
 404     /*LFT_REQUEST_SIZE_BODY, */
 405     /*LFT_REQUEST_SIZE_BODY_NO_TE, */
 406
 407     LFT_REPLY_SIZE_TOTAL,
 408     LFT_REPLY_HIGHOFFSET,
 409     LFT_REPLY_OBJECTSIZE,
 410     /*LFT_REPLY_SIZE_LINE, */
 411     LFT_REPLY_SIZE_HEADERS,
 412     /*LFT_REPLY_SIZE_BODY, */
 413     /*LFT_REPLY_SIZE_BODY_NO_TE, */
 414
 415     LFT_TAG,
 416     LFT_IO_SIZE_TOTAL,
 417     LFT_EXT_LOG,
 418
 419     LFT_SEQUENCE_NUMBER,
 420
 421 #if USE_ADAPTATION
 422     LTF_ADAPTATION_SUM_XACT_TIMES,
 423     LTF_ADAPTATION_ALL_XACT_TIMES,
 424     LFT_ADAPTATION_LAST_HEADER,
 425     LFT_ADAPTATION_LAST_HEADER_ELEM,
 426     LFT_ADAPTATION_LAST_ALL_HEADERS,
 427 #endif
 428
 429 #if ICAP_CLIENT
 430
 431     LFT_ICAP_TOTAL_TIME,
 432
 433     LFT_ICAP_ADDR,
 434     LFT_ICAP_SERV_NAME,
 435     LFT_ICAP_REQUEST_URI,
 436     LFT_ICAP_REQUEST_METHOD,
 437     LFT_ICAP_BYTES_SENT,
 438     LFT_ICAP_BYTES_READ,
 439     LFT_ICAP_BODY_BYTES_READ,
 440
 441     LFT_ICAP_REQ_HEADER,
 442     LFT_ICAP_REQ_HEADER_ELEM,
 443     LFT_ICAP_REQ_ALL_HEADERS,
 444
 445     LFT_ICAP_REP_HEADER,
 446     LFT_ICAP_REP_HEADER_ELEM,
 447     LFT_ICAP_REP_ALL_HEADERS,
 448
 449     LFT_ICAP_TR_RESPONSE_TIME,
 450     LFT_ICAP_IO_TIME,
 451     LFT_ICAP_OUTCOME,
 452     LFT_ICAP_STATUS_CODE,
 453 #endif
 454
 455     LFT_PERCENT                 /* special string cases for escaped chars */
 456 } logformat_bcode_t;
 457
 458 enum log_quote {
 459     LOG_QUOTE_NONE = 0,
 460     LOG_QUOTE_QUOTES,
 461     LOG_QUOTE_BRAKETS,
 462     LOG_QUOTE_URL,
 463     LOG_QUOTE_RAW
 464 };
 465
 466 /* FIXME: public class so we can pre-define its type. */
 467 class logformat_token
 468 {
 469 public:
 470     logformat_bcode_t type;
 471     union {
 472         char *string;
 473
 474         struct {
 475             char *header;
 476             char *element;
 477             char separator;
 478         } header;
 479         char *timespec;
 480     } data;
 481     unsigned char width;
 482     unsigned char precision;
 483     enum log_quote quote;
 484     unsigned int left:1;
 485     unsigned int space:1;
 486     unsigned int zero:1;
 487     int divisor;
 488     logformat_token *next;      /* todo: move from linked list to array */
 489 };
 490
 491 struct logformat_token_table_entry {
 492     const char *config;
 493     logformat_bcode_t token_type;
 494     int options;
 495 };
 496
 497 struct logformat_token_table_entry logformat_token_table[] = {
 498
 499     {">a", LFT_CLIENT_IP_ADDRESS},
 500     {">p", LFT_CLIENT_PORT},
 501     {">A", LFT_CLIENT_FQDN},
 502 #if USE_SQUID_EUI
 503     {">eui", LFT_CLIENT_EUI},
 504 #endif
 505
 506     /*{ "<a", LFT_SERVER_IP_ADDRESS }, */
 507     /*{ "<p", LFT_SERVER_PORT }, */
 508     {"<A", LFT_SERVER_IP_OR_PEER_NAME},
 509
 510     /* {"oa", LFT_OUTGOING_IP}, */
 511     /* {"ot", LFT_OUTGOING_TOS}, */
 512
 513     {"la", LFT_LOCAL_IP},
 514     {"lp", LFT_LOCAL_PORT},
 515     /*{ "lA", LFT_LOCAL_NAME }, */
 516     {"<lp", LFT_PEER_LOCAL_PORT},
 517
 518     {"ts", LFT_TIME_SECONDS_SINCE_EPOCH},
 519     {"tu", LFT_TIME_SUBSECOND},
 520     {"tl", LFT_TIME_LOCALTIME},
 521     {"tg", LFT_TIME_GMT},
 522     {"tr", LFT_TIME_TO_HANDLE_REQUEST},
 523
 524     {"<pt", LFT_PEER_RESPONSE_TIME},
 525     {"<tt", LFT_TOTAL_SERVER_SIDE_RESPONSE_TIME},
 526     {"dt", LFT_DNS_WAIT_TIME},
 527
 528     {">ha", LFT_ADAPTED_REQUEST_HEADER},
 529     {">ha", LFT_ADAPTED_REQUEST_ALL_HEADERS},
 530     {">h", LFT_REQUEST_HEADER},
 531     {">h", LFT_REQUEST_ALL_HEADERS},
 532     {"<h", LFT_REPLY_HEADER},
 533     {"<h", LFT_REPLY_ALL_HEADERS},
 534
 535     {"un", LFT_USER_NAME},
 536     {"ul", LFT_USER_LOGIN},
 537     /*{ "ur", LFT_USER_REALM }, */
 538     /*{ "us", LFT_USER_SCHEME }, */
 539     {"ui", LFT_USER_IDENT},
 540     {"ue", LFT_USER_EXTERNAL},
 541
 542     {"Hs", LFT_HTTP_SENT_STATUS_CODE_OLD_30},
 543     {">Hs", LFT_HTTP_SENT_STATUS_CODE},
 544     {"<Hs", LFT_HTTP_RECEIVED_STATUS_CODE},
 545     /*{ "Ht", LFT_HTTP_STATUS }, */
 546     {"<bs", LFT_HTTP_BODY_BYTES_READ},
 547
 548     {"Ss", LFT_SQUID_STATUS},
 549     { "err_code", LFT_SQUID_ERROR },
 550     { "err_detail", LFT_SQUID_ERROR_DETAIL },
 551     {"Sh", LFT_SQUID_HIERARCHY},
 552
 553     {"mt", LFT_MIME_TYPE},
 554
 555     {"rm", LFT_REQUEST_METHOD},
 556     {"ru", LFT_REQUEST_URI},    /* doesn't include the query-string */
 557     {"rp", LFT_REQUEST_URLPATH},        /* doesn't include the host */
 558     /* { "rq", LFT_REQUEST_QUERY }, * /     / * the query-string, INCLUDING the leading ? */
 559     {">v", LFT_REQUEST_VERSION},
 560     {"rv", LFT_REQUEST_VERSION},
 561
 562     { ">st", LFT_REQUEST_SIZE_TOTAL },
 563     /*{ ">sl", LFT_REQUEST_SIZE_LINE }, * / / * the request line "GET ... " */
 564     { ">sh", LFT_REQUEST_SIZE_HEADERS },
 565     /*{ ">sb", LFT_REQUEST_SIZE_BODY }, */
 566     /*{ ">sB", LFT_REQUEST_SIZE_BODY_NO_TE }, */
 567
 568     {"<st", LFT_REPLY_SIZE_TOTAL},
 569     {"<sH", LFT_REPLY_HIGHOFFSET},
 570     {"<sS", LFT_REPLY_OBJECTSIZE},
 571     /*{ "<sl", LFT_REPLY_SIZE_LINE }, * /   / * the reply line (protocol, code, text) */
 572     { "<sh", LFT_REPLY_SIZE_HEADERS },
 573     /*{ "<sb", LFT_REPLY_SIZE_BODY }, */
 574     /*{ "<sB", LFT_REPLY_SIZE_BODY_NO_TE }, */
 575
 576     {"et", LFT_TAG},
 577     {"st", LFT_IO_SIZE_TOTAL},
 578     {"ea", LFT_EXT_LOG},
 579     {"sn", LFT_SEQUENCE_NUMBER},
 580
 581     {"%", LFT_PERCENT},
 582
 583 #if USE_ADAPTATION
 584     {"adapt::all_trs", LTF_ADAPTATION_ALL_XACT_TIMES},
 585     {"adapt::sum_trs", LTF_ADAPTATION_SUM_XACT_TIMES},
 586     {"adapt::<last_h", LFT_ADAPTATION_LAST_HEADER},
 587 #endif
 588
 589 #if ICAP_CLIENT
 590     {"icap::tt", LFT_ICAP_TOTAL_TIME},
 591     {"icap::<last_h", LFT_ADAPTATION_LAST_HEADER}, // deprecated
 592
 593     {"icap::<A",  LFT_ICAP_ADDR},
 594     {"icap::<service_name",  LFT_ICAP_SERV_NAME},
 595     {"icap::ru",  LFT_ICAP_REQUEST_URI},
 596     {"icap::rm",  LFT_ICAP_REQUEST_METHOD},
 597     {"icap::>st",  LFT_ICAP_BYTES_SENT},
 598     {"icap::<st",  LFT_ICAP_BYTES_READ},
 599     {"icap::<bs", LFT_ICAP_BODY_BYTES_READ},
 600
 601     {"icap::>h",  LFT_ICAP_REQ_HEADER},
 602     {"icap::<h",  LFT_ICAP_REP_HEADER},
 603
 604     {"icap::tr",  LFT_ICAP_TR_RESPONSE_TIME},
 605     {"icap::tio",  LFT_ICAP_IO_TIME},
 606     {"icap::to",  LFT_ICAP_OUTCOME},
 607     {"icap::Hs",  LFT_ICAP_STATUS_CODE},
 608 #endif
 609
 610     {NULL, LFT_NONE}            /* this must be last */
 611 };
 612
 613 static void
 614 accessLogCustom(AccessLogEntry * al, customlog * log)
 615 {
 616     logformat *lf;
 617     Logfile *logfile;
 618     logformat_token *fmt;
 619     static MemBuf mb;
 620     char tmp[1024];
 621     String sb;
 622
 623     mb.reset();
 624
 625     lf = log->logFormat;
 626     logfile = log->logfile;
 627
 628     for (fmt = lf->format; fmt != NULL; fmt = fmt->next) {      /* for each token */
 629         const char *out = NULL;
 630         int quote = 0;
 631         long int outint = 0;
 632         int doint = 0;
 633         int dofree = 0;
 634         int64_t outoff = 0;
 635         int dooff = 0;
 636
 637         switch (fmt->type) {
 638
 639         case LFT_NONE:
 640             out = "";
 641             break;
 642
 643         case LFT_STRING:
 644             out = fmt->data.string;
 645             break;
 646
 647         case LFT_CLIENT_IP_ADDRESS:
 648             if (al->cache.caddr.IsNoAddr()) // e.g., ICAP OPTIONS lack client
 649                 out = "-";
 650             else
 651                 out = al->cache.caddr.NtoA(tmp,1024);
 652             break;
 653
 654         case LFT_CLIENT_FQDN:
 655             if (al->cache.caddr.IsAnyAddr()) // e.g., ICAP OPTIONS lack client
 656                 out = "-";
 657             else
 658                 out = fqdncache_gethostbyaddr(al->cache.caddr, FQDN_LOOKUP_IF_MISS);
 659             if (!out) {
 660                 out = al->cache.caddr.NtoA(tmp,1024);
 661             }
 662
 663             break;
 664
 665         case LFT_CLIENT_PORT:
 666             if (al->request) {
 667                 outint = al->request->client_addr.GetPort();
 668                 doint = 1;
 669             }
 670             break;
 671
 672 #if USE_SQUID_EUI
 673         case LFT_CLIENT_EUI:
 674             if (al->request) {
 675                 if (al->cache.caddr.IsIPv4())
 676                     al->request->client_eui48.encode(tmp, 1024);
 677                 else
 678                     al->request->client_eui64.encode(tmp, 1024);
 679                 out = tmp;
 680             }
 681             break;
 682 #endif
 683
 684             /* case LFT_SERVER_IP_ADDRESS: */
 685
 686         case LFT_SERVER_IP_OR_PEER_NAME:
 687             out = al->hier.host;
 688
 689             break;
 690
 691             /* case LFT_SERVER_PORT: */
 692
 693         case LFT_LOCAL_IP:
 694             if (al->request) {
 695                 out = al->request->my_addr.NtoA(tmp,1024);
 696             }
 697
 698             break;
 699
 700         case LFT_LOCAL_PORT:
 701             if (al->request) {
 702                 outint = al->request->my_addr.GetPort();
 703                 doint = 1;
 704             }
 705
 706             break;
 707
 708         case LFT_PEER_LOCAL_PORT:
 709             if (al->hier.peer_local_port) {
 710                 outint = al->hier.peer_local_port;
 711                 doint = 1;
 712             }
 713
 714             break;
 715
 716         case LFT_TIME_SECONDS_SINCE_EPOCH:
 717             // some platforms store time in 32-bit, some 64-bit...
 718             outoff = static_cast<int64_t>(current_time.tv_sec);
 719             dooff = 1;
 720             break;
 721
 722         case LFT_TIME_SUBSECOND:
 723             outint = current_time.tv_usec / fmt->divisor;
 724             doint = 1;
 725             break;
 726
 727
 728         case LFT_TIME_LOCALTIME:
 729
 730         case LFT_TIME_GMT: {
 731             const char *spec;
 732
 733             struct tm *t;
 734             spec = fmt->data.timespec;
 735
 736             if (fmt->type == LFT_TIME_LOCALTIME) {
 737                 if (!spec)
 738                     spec = "%d/%b/%Y:%H:%M:%S %z";
 739                 t = localtime(&squid_curtime);
 740             } else {
 741                 if (!spec)
 742                     spec = "%d/%b/%Y:%H:%M:%S";
 743
 744                 t = gmtime(&squid_curtime);
 745             }
 746
 747             strftime(tmp, sizeof(tmp), spec, t);
 748
 749             out = tmp;
 750         }
 751
 752         break;
 753
 754         case LFT_TIME_TO_HANDLE_REQUEST:
 755             outint = al->cache.msec;
 756             doint = 1;
 757             break;
 758
 759         case LFT_PEER_RESPONSE_TIME:
 760             if (al->hier.peer_response_time < 0) {
 761                 out = "-";
 762             } else {
 763                 outoff = al->hier.peer_response_time;
 764                 dooff = 1;
 765             }
 766             break;
 767
 768         case LFT_TOTAL_SERVER_SIDE_RESPONSE_TIME:
 769             if (al->hier.total_response_time < 0) {
 770                 out = "-";
 771             } else {
 772                 outoff = al->hier.total_response_time;
 773                 dooff = 1;
 774             }
 775             break;
 776
 777         case LFT_DNS_WAIT_TIME:
 778             if (al->request && al->request->dnsWait >= 0) {
 779                 outint = al->request->dnsWait;
 780                 doint = 1;
 781             }
 782             break;
 783
 784         case LFT_REQUEST_HEADER:
 785
 786             if (al->request)
 787                 sb = al->request->header.getByName(fmt->data.header.header);
 788
 789             out = sb.termedBuf();
 790
 791             quote = 1;
 792
 793             break;
 794
 795         case LFT_ADAPTED_REQUEST_HEADER:
 796
 797             if (al->request)
 798                 sb = al->adapted_request->header.getByName(fmt->data.header.header);
 799
 800             out = sb.termedBuf();
 801
 802             quote = 1;
 803
 804             break;
 805
 806         case LFT_REPLY_HEADER:
 807             if (al->reply)
 808                 sb = al->reply->header.getByName(fmt->data.header.header);
 809
 810             out = sb.termedBuf();
 811
 812             quote = 1;
 813
 814             break;
 815
 816 #if USE_ADAPTATION
 817         case LTF_ADAPTATION_SUM_XACT_TIMES:
 818             if (al->request) {
 819                 Adaptation::History::Pointer ah = al->request->adaptHistory();
 820                 if (ah != NULL)
 821                     ah->sumLogString(fmt->data.string, sb);
 822                 out = sb.termedBuf();
 823             }
 824             break;
 825
 826         case LTF_ADAPTATION_ALL_XACT_TIMES:
 827             if (al->request) {
 828                 Adaptation::History::Pointer ah = al->request->adaptHistory();
 829                 if (ah != NULL)
 830                     ah->allLogString(fmt->data.string, sb);
 831                 out = sb.termedBuf();
 832             }
 833             break;
 834
 835         case LFT_ADAPTATION_LAST_HEADER:
 836             if (al->request) {
 837                 const Adaptation::History::Pointer ah = al->request->adaptHistory();
 838                 if (ah != NULL) // XXX: add adapt::<all_h but use lastMeta here
 839                     sb = ah->allMeta.getByName(fmt->data.header.header);
 840             }
 841
 842             // XXX: here and elsewhere: move such code inside the if guard
 843             out = sb.termedBuf();
 844
 845             quote = 1;
 846
 847             break;
 848
 849         case LFT_ADAPTATION_LAST_HEADER_ELEM:
 850             if (al->request) {
 851                 const Adaptation::History::Pointer ah = al->request->adaptHistory();
 852                 if (ah != NULL) // XXX: add adapt::<all_h but use lastMeta here
 853                     sb = ah->allMeta.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
 854             }
 855
 856             out = sb.termedBuf();
 857
 858             quote = 1;
 859
 860             break;
 861
 862         case LFT_ADAPTATION_LAST_ALL_HEADERS:
 863             out = al->headers.adapt_last;
 864
 865             quote = 1;
 866
 867             break;
 868 #endif
 869
 870 #if ICAP_CLIENT
 871         case LFT_ICAP_ADDR:
 872             if (!out)
 873                 out = al->icap.hostAddr.NtoA(tmp,1024);
 874             break;
 875
 876         case LFT_ICAP_SERV_NAME:
 877             out = al->icap.serviceName.termedBuf();
 878             break;
 879
 880         case LFT_ICAP_REQUEST_URI:
 881             out = al->icap.reqUri.termedBuf();
 882             break;
 883
 884         case LFT_ICAP_REQUEST_METHOD:
 885             out = Adaptation::Icap::ICAP::methodStr(al->icap.reqMethod);
 886             break;
 887
 888         case LFT_ICAP_BYTES_SENT:
 889             outoff = al->icap.bytesSent;
 890             dooff = 1;
 891             break;
 892
 893         case LFT_ICAP_BYTES_READ:
 894             outoff = al->icap.bytesRead;
 895             dooff = 1;
 896             break;
 897
 898         case LFT_ICAP_BODY_BYTES_READ:
 899             if (al->icap.bodyBytesRead >= 0) {
 900                 outoff = al->icap.bodyBytesRead;
 901                 dooff = 1;
 902             }
 903             // else if icap.bodyBytesRead < 0, we do not have any http data,
 904             // so just print a "-" (204 responses etc)
 905             break;
 906
 907         case LFT_ICAP_REQ_HEADER:
 908             if (NULL != al->icap.request) {
 909                 sb = al->icap.request->header.getByName(fmt->data.header.header);
 910                 out = sb.termedBuf();
 911                 quote = 1;
 912             }
 913             break;
 914
 915         case LFT_ICAP_REQ_HEADER_ELEM:
 916             if (al->request)
 917                 sb = al->icap.request->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
 918
 919             out = sb.termedBuf();
 920
 921             quote = 1;
 922
 923             break;
 924
 925         case LFT_ICAP_REQ_ALL_HEADERS:
 926             if (al->icap.request) {
 927                 HttpHeaderPos pos = HttpHeaderInitPos;
 928                 while (const HttpHeaderEntry *e = al->icap.request->header.getEntry(&pos)) {
 929                     sb.append(e->name);
 930                     sb.append(": ");
 931                     sb.append(e->value);
 932                     sb.append("\r\n");
 933                 }
 934                 out = sb.termedBuf();
 935                 quote = 1;
 936             }
 937             break;
 938
 939         case LFT_ICAP_REP_HEADER:
 940             if (NULL != al->icap.reply) {
 941                 sb = al->icap.reply->header.getByName(fmt->data.header.header);
 942                 out = sb.termedBuf();
 943                 quote = 1;
 944             }
 945             break;
 946
 947         case LFT_ICAP_REP_HEADER_ELEM:
 948             if (NULL != al->icap.reply)
 949                 sb = al->icap.reply->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
 950
 951             out = sb.termedBuf();
 952
 953             quote = 1;
 954
 955             break;
 956
 957         case LFT_ICAP_REP_ALL_HEADERS:
 958             if (al->icap.reply) {
 959                 HttpHeaderPos pos = HttpHeaderInitPos;
 960                 while (const HttpHeaderEntry *e = al->icap.reply->header.getEntry(&pos)) {
 961                     sb.append(e->name);
 962                     sb.append(": ");
 963                     sb.append(e->value);
 964                     sb.append("\r\n");
 965                 }
 966                 out = sb.termedBuf();
 967                 quote = 1;
 968             }
 969             break;
 970
 971         case LFT_ICAP_TR_RESPONSE_TIME:
 972             outint = al->icap.trTime;
 973             doint = 1;
 974             break;
 975
 976         case LFT_ICAP_IO_TIME:
 977             outint = al->icap.ioTime;
 978             doint = 1;
 979             break;
 980
 981         case LFT_ICAP_STATUS_CODE:
 982             outint = al->icap.resStatus;
 983             doint  = 1;
 984             break;
 985
 986         case LFT_ICAP_OUTCOME:
 987             out = al->icap.outcome;
 988             break;
 989
 990         case LFT_ICAP_TOTAL_TIME:
 991             outint = al->icap.processingTime;
 992             doint = 1;
 993             break;
 994 #endif
 995         case LFT_REQUEST_HEADER_ELEM:
 996             if (al->request)
 997                 sb = al->request->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
 998
 999             out = sb.termedBuf();
1000
1001             quote = 1;
1002
1003             break;
1004
1005         case LFT_ADAPTED_REQUEST_HEADER_ELEM:
1006             if (al->adapted_request)
1007                 sb = al->adapted_request->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
1008
1009             out = sb.termedBuf();
1010
1011             quote = 1;
1012
1013             break;
1014
1015         case LFT_REPLY_HEADER_ELEM:
1016             if (al->reply)
1017                 sb = al->reply->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
1018
1019             out = sb.termedBuf();
1020
1021             quote = 1;
1022
1023             break;
1024
1025         case LFT_REQUEST_ALL_HEADERS:
1026             out = al->headers.request;
1027
1028             quote = 1;
1029
1030             break;
1031
1032         case LFT_ADAPTED_REQUEST_ALL_HEADERS:
1033             out = al->headers.adapted_request;
1034
1035             quote = 1;
1036
1037             break;
1038
1039         case LFT_REPLY_ALL_HEADERS:
1040             out = al->headers.reply;
1041
1042             quote = 1;
1043
1044             break;
1045
1046         case LFT_USER_NAME:
1047             out = accessLogFormatName(al->cache.authuser);
1048
1049             if (!out)
1050                 out = accessLogFormatName(al->cache.extuser);
1051
1052 #if USE_SSL
1053
1054             if (!out)
1055                 out = accessLogFormatName(al->cache.ssluser);
1056
1057 #endif
1058
1059             if (!out)
1060                 out = accessLogFormatName(al->cache.rfc931);
1061
1062             dofree = 1;
1063
1064             break;
1065
1066         case LFT_USER_LOGIN:
1067             out = accessLogFormatName(al->cache.authuser);
1068
1069             dofree = 1;
1070
1071             break;
1072
1073         case LFT_USER_IDENT:
1074             out = accessLogFormatName(al->cache.rfc931);
1075
1076             dofree = 1;
1077
1078             break;
1079
1080         case LFT_USER_EXTERNAL:
1081             out = accessLogFormatName(al->cache.extuser);
1082
1083             dofree = 1;
1084
1085             break;
1086
1087             /* case LFT_USER_REALM: */
1088             /* case LFT_USER_SCHEME: */
1089
1090             // the fmt->type can not be LFT_HTTP_SENT_STATUS_CODE_OLD_30
1091             // but compiler complains if ommited
1092         case LFT_HTTP_SENT_STATUS_CODE_OLD_30:
1093         case LFT_HTTP_SENT_STATUS_CODE:
1094             outint = al->http.code;
1095
1096             doint = 1;
1097
1098             break;
1099
1100         case LFT_HTTP_RECEIVED_STATUS_CODE:
1101             if (al->hier.peer_reply_status == HTTP_STATUS_NONE) {
1102                 out = "-";
1103             } else {
1104                 outint = al->hier.peer_reply_status;
1105                 doint = 1;
1106             }
1107             break;
1108             /* case LFT_HTTP_STATUS:
1109              *           out = statusline->text;
1110              *     quote = 1;
1111              *     break;
1112              */
1113         case LFT_HTTP_BODY_BYTES_READ:
1114             if (al->hier.bodyBytesRead >= 0) {
1115                 outoff = al->hier.bodyBytesRead;
1116                 dooff = 1;
1117             }
1118             // else if hier.bodyBytesRead < 0 we did not have any data exchange with
1119             // a peer server so just print a "-" (eg requests served from cache,
1120             // or internal error messages).
1121             break;
1122
1123         case LFT_SQUID_STATUS:
1124             if (al->http.timedout || al->http.aborted) {
1125                 snprintf(tmp, sizeof(tmp), "%s%s", log_tags[al->cache.code],
1126                          al->http.statusSfx());
1127                 out = tmp;
1128             } else {
1129                 out = log_tags[al->cache.code];
1130             }
1131
1132             break;
1133
1134         case LFT_SQUID_ERROR:
1135             if (al->request && al->request->errType != ERR_NONE)
1136                 out = errorPageName(al->request->errType);
1137             break;
1138
1139         case LFT_SQUID_ERROR_DETAIL:
1140             if (al->request && al->request->errDetail != ERR_DETAIL_NONE) {
1141                 if (al->request->errDetail > ERR_DETAIL_START  &&
1142                         al->request->errDetail < ERR_DETAIL_MAX)
1143                     out = errorDetailName(al->request->errDetail);
1144                 else {
1145                     if (al->request->errDetail >= ERR_DETAIL_EXCEPTION_START)
1146                         snprintf(tmp, sizeof(tmp), "%s=0x%X",
1147                                  errorDetailName(al->request->errDetail), (uint32_t) al->request->errDetail);
1148                     else
1149                         snprintf(tmp, sizeof(tmp), "%s=%d",
1150                                  errorDetailName(al->request->errDetail), al->request->errDetail);
1151                     out = tmp;
1152                 }
1153             }
1154             break;
1155
1156         case LFT_SQUID_HIERARCHY:
1157             if (al->hier.ping.timedout)
1158                 mb.append("TIMEOUT_", 8);
1159
1160             out = hier_code_str[al->hier.code];
1161
1162             break;
1163
1164         case LFT_MIME_TYPE:
1165             out = al->http.content_type;
1166
1167             break;
1168
1169         case LFT_REQUEST_METHOD:
1170             out = al->_private.method_str;
1171
1172             break;
1173
1174         case LFT_REQUEST_URI:
1175             out = al->url;
1176
1177             break;
1178
1179         case LFT_REQUEST_URLPATH:
1180             if (al->request) {
1181                 out = al->request->urlpath.termedBuf();
1182                 quote = 1;
1183             }
1184             break;
1185
1186         case LFT_REQUEST_VERSION:
1187             snprintf(tmp, sizeof(tmp), "%d.%d", (int) al->http.version.major, (int) al->http.version.minor);
1188             out = tmp;
1189             break;
1190
1191         case LFT_REQUEST_SIZE_TOTAL:
1192             outoff = al->cache.requestSize;
1193             dooff = 1;
1194             break;
1195
1196             /*case LFT_REQUEST_SIZE_LINE: */
1197         case LFT_REQUEST_SIZE_HEADERS:
1198             outoff = al->cache.requestHeadersSize;
1199             dooff =1;
1200             break;
1201             /*case LFT_REQUEST_SIZE_BODY: */
1202             /*case LFT_REQUEST_SIZE_BODY_NO_TE: */
1203
1204         case LFT_REPLY_SIZE_TOTAL:
1205             outoff = al->cache.replySize;
1206             dooff = 1;
1207             break;
1208
1209         case LFT_REPLY_HIGHOFFSET:
1210             outoff = al->cache.highOffset;
1211
1212             dooff = 1;
1213
1214             break;
1215
1216         case LFT_REPLY_OBJECTSIZE:
1217             outoff = al->cache.objectSize;
1218
1219             dooff = 1;
1220
1221             break;
1222
1223             /*case LFT_REPLY_SIZE_LINE: */
1224         case LFT_REPLY_SIZE_HEADERS:
1225             outint = al->cache.replyHeadersSize;
1226             doint = 1;
1227             break;
1228             /*case LFT_REPLY_SIZE_BODY: */
1229             /*case LFT_REPLY_SIZE_BODY_NO_TE: */
1230
1231         case LFT_TAG:
1232             if (al->request)
1233                 out = al->request->tag.termedBuf();
1234
1235             quote = 1;
1236
1237             break;
1238
1239         case LFT_IO_SIZE_TOTAL:
1240             outint = al->cache.requestSize + al->cache.replySize;
1241             doint = 1;
1242             break;
1243
1244         case LFT_EXT_LOG:
1245             if (al->request)
1246                 out = al->request->extacl_log.termedBuf();
1247
1248             quote = 1;
1249
1250             break;
1251
1252         case LFT_SEQUENCE_NUMBER:
1253             outoff = logfile->sequence_number;
1254             dooff = 1;
1255             break;
1256
1257         case LFT_PERCENT:
1258             out = "%";
1259
1260             break;
1261         }
1262
1263         if (dooff) {
1264             snprintf(tmp, sizeof(tmp), "%0*" PRId64, fmt->zero ? (int) fmt->width : 0, outoff);
1265             out = tmp;
1266
1267         } else if (doint) {
1268             snprintf(tmp, sizeof(tmp), "%0*ld", fmt->zero ? (int) fmt->width : 0, outint);
1269             out = tmp;
1270         }
1271
1272         if (out && *out) {
1273             if (quote || fmt->quote != LOG_QUOTE_NONE) {
1274                 char *newout = NULL;
1275                 int newfree = 0;
1276
1277                 switch (fmt->quote) {
1278
1279                 case LOG_QUOTE_NONE:
1280                     newout = rfc1738_escape_unescaped(out);
1281                     break;
1282
1283                 case LOG_QUOTE_QUOTES:
1284                     newout = log_quoted_string(out);
1285                     newfree = 1;
1286                     break;
1287
1288                 case LOG_QUOTE_BRAKETS:
1289                     newout = log_quote(out);
1290                     newfree = 1;
1291                     break;
1292
1293                 case LOG_QUOTE_URL:
1294                     newout = rfc1738_escape(out);
1295                     break;
1296
1297                 case LOG_QUOTE_RAW:
1298                     break;
1299                 }
1300
1301                 if (newout) {
1302                     if (dofree)
1303                         safe_free(out);
1304
1305                     out = newout;
1306
1307                     dofree = newfree;
1308                 }
1309             }
1310
1311             if (fmt->width) {
1312                 if (fmt->left)
1313                     mb.Printf("%-*s", (int) fmt->width, out);
1314                 else
1315                     mb.Printf("%*s", (int) fmt->width, out);
1316             } else
1317                 mb.append(out, strlen(out));
1318         } else {
1319             mb.append("-", 1);
1320         }
1321
1322         if (fmt->space)
1323             mb.append(" ", 1);
1324
1325         sb.clean();
1326
1327         if (dofree)
1328             safe_free(out);
1329     }
1330
1331     logfilePrintf(logfile, "%s\n", mb.buf);
1332 }
1333
1334 /* parses a single token. Returns the token length in characters,
1335  * and fills in the lt item with the token information.
1336  * def is for sure null-terminated
1337  */
1338 static int
1339 accessLogGetNewLogFormatToken(logformat_token * lt, char *def, enum log_quote *quote)
1340 {
1341     char *cur = def;
1342
1343     struct logformat_token_table_entry *lte;
1344     int l;
1345
1346     memset(lt, 0, sizeof(*lt));
1347     l = strcspn(cur, "%");
1348
1349     if (l > 0) {
1350         char *cp;
1351         /* it's a string for sure, until \0 or the next % */
1352         cp = (char *)xmalloc(l + 1);
1353         xstrncpy(cp, cur, l + 1);
1354         lt->type = LFT_STRING;
1355         lt->data.string = cp;
1356
1357         while (l > 0) {
1358             switch (*cur) {
1359
1360             case '"':
1361
1362                 if (*quote == LOG_QUOTE_NONE)
1363                     *quote = LOG_QUOTE_QUOTES;
1364                 else if (*quote == LOG_QUOTE_QUOTES)
1365                     *quote = LOG_QUOTE_NONE;
1366
1367                 break;
1368
1369             case '[':
1370                 if (*quote == LOG_QUOTE_NONE)
1371                     *quote = LOG_QUOTE_BRAKETS;
1372
1373                 break;
1374
1375             case ']':
1376                 if (*quote == LOG_QUOTE_BRAKETS)
1377                     *quote = LOG_QUOTE_NONE;
1378
1379                 break;
1380             }
1381
1382             cur++;
1383             l--;
1384         }
1385
1386         goto done;
1387     }
1388
1389     if (!*cur)
1390         goto done;
1391
1392     cur++;
1393
1394     switch (*cur) {
1395
1396     case '"':
1397         lt->quote = LOG_QUOTE_QUOTES;
1398         cur++;
1399         break;
1400
1401     case '\'':
1402         lt->quote = LOG_QUOTE_RAW;
1403         cur++;
1404         break;
1405
1406     case '[':
1407         lt->quote = LOG_QUOTE_BRAKETS;
1408         cur++;
1409         break;
1410
1411     case '#':
1412         lt->quote = LOG_QUOTE_URL;
1413         cur++;
1414         break;
1415
1416     default:
1417         lt->quote = *quote;
1418         break;
1419     }
1420
1421     if (*cur == '-') {
1422         lt->left = 1;
1423         cur++;
1424     }
1425
1426     if (*cur == '0') {
1427         lt->zero = 1;
1428         cur++;
1429     }
1430
1431     if (xisdigit(*cur))
1432         lt->width = strtol(cur, &cur, 10);
1433
1434     if (*cur == '.')
1435         lt->precision = strtol(cur + 1, &cur, 10);
1436
1437     if (*cur == '{') {
1438         char *cp;
1439         cur++;
1440         l = strcspn(cur, "}");
1441         cp = (char *)xmalloc(l + 1);
1442         xstrncpy(cp, cur, l + 1);
1443         lt->data.string = cp;
1444         cur += l;
1445
1446         if (*cur == '}')
1447             cur++;
1448     }
1449
1450     // For upward compatibility, assume "http::" prefix as default prefix
1451     // for all log access formating codes, except those starting
1452     // from "icap::", "adapt::" and "%"
1453     if (strncmp(cur,"http::", 6) == 0 &&
1454             strncmp(cur+6, "icap::", 6) != 0  &&
1455             strncmp(cur+6, "adapt::", 12) != 0 && *(cur+6) != '%' ) {
1456         cur += 6;
1457     }
1458
1459     lt->type = LFT_NONE;
1460
1461     for (lte = logformat_token_table; lte->config != NULL; lte++) {
1462         if (strncmp(lte->config, cur, strlen(lte->config)) == 0) {
1463             lt->type = lte->token_type;
1464             cur += strlen(lte->config);
1465             break;
1466         }
1467     }
1468
1469     if (lt->type == LFT_NONE) {
1470         fatalf("Can't parse configuration token: '%s'\n",
1471                def);
1472     }
1473
1474     if (*cur == ' ') {
1475         lt->space = 1;
1476         cur++;
1477     }
1478
1479 done:
1480
1481     switch (lt->type) {
1482
1483 #if USE_ADAPTATION
1484     case LFT_ADAPTATION_LAST_HEADER:
1485 #endif
1486
1487 #if ICAP_CLIENT
1488     case LFT_ICAP_REQ_HEADER:
1489
1490     case LFT_ICAP_REP_HEADER:
1491 #endif
1492
1493     case LFT_ADAPTED_REQUEST_HEADER:
1494
1495     case LFT_REQUEST_HEADER:
1496
1497     case LFT_REPLY_HEADER:
1498
1499         if (lt->data.string) {
1500             char *header = lt->data.string;
1501             char *cp = strchr(header, ':');
1502
1503             if (cp) {
1504                 *cp++ = '\0';
1505
1506                 if (*cp == ',' || *cp == ';' || *cp == ':')
1507                     lt->data.header.separator = *cp++;
1508                 else
1509                     lt->data.header.separator = ',';
1510
1511                 lt->data.header.element = cp;
1512
1513                 switch (lt->type) {
1514                 case LFT_REQUEST_HEADER:
1515                     lt->type = LFT_REQUEST_HEADER_ELEM;
1516                     break;
1517
1518                 case LFT_ADAPTED_REQUEST_HEADER:
1519                     lt->type = LFT_ADAPTED_REQUEST_HEADER_ELEM;
1520                     break;
1521
1522                 case LFT_REPLY_HEADER:
1523                     lt->type = LFT_REPLY_HEADER_ELEM;
1524                     break;
1525 #if USE_ADAPTATION
1526                 case LFT_ADAPTATION_LAST_HEADER:
1527                     lt->type = LFT_ADAPTATION_LAST_HEADER_ELEM;
1528                     break;
1529 #endif
1530 #if ICAP_CLIENT
1531                 case LFT_ICAP_REQ_HEADER:
1532                     lt->type = LFT_ICAP_REQ_HEADER_ELEM;
1533                     break;
1534                 case LFT_ICAP_REP_HEADER:
1535                     lt->type = LFT_ICAP_REP_HEADER_ELEM;
1536                     break;
1537 #endif
1538                 default:
1539                     break;
1540                 }
1541             }
1542
1543             lt->data.header.header = header;
1544         } else {
1545             switch (lt->type) {
1546             case LFT_REQUEST_HEADER:
1547                 lt->type = LFT_REQUEST_ALL_HEADERS;
1548                 break;
1549
1550             case LFT_ADAPTED_REQUEST_HEADER:
1551                 lt->type = LFT_ADAPTED_REQUEST_ALL_HEADERS;
1552                 break;
1553
1554             case LFT_REPLY_HEADER:
1555                 lt->type = LFT_REPLY_ALL_HEADERS;
1556                 break;
1557 #if USE_ADAPTATION
1558             case LFT_ADAPTATION_LAST_HEADER:
1559                 lt->type = LFT_ADAPTATION_LAST_ALL_HEADERS;
1560                 break;
1561 #endif
1562 #if ICAP_CLIENT
1563             case LFT_ICAP_REQ_HEADER:
1564                 lt->type = LFT_ICAP_REQ_ALL_HEADERS;
1565                 break;
1566             case LFT_ICAP_REP_HEADER:
1567                 lt->type = LFT_ICAP_REP_ALL_HEADERS;
1568                 break;
1569 #endif
1570             default:
1571                 break;
1572             }
1573             Config.onoff.log_mime_hdrs = 1;
1574         }
1575
1576         break;
1577
1578     case LFT_CLIENT_FQDN:
1579         Config.onoff.log_fqdn = 1;
1580         break;
1581
1582     case LFT_TIME_SUBSECOND:
1583         lt->divisor = 1000;
1584
1585         if (lt->precision) {
1586             int i;
1587             lt->divisor = 1000000;
1588
1589             for (i = lt->precision; i > 1; i--)
1590                 lt->divisor /= 10;
1591
1592             if (!lt->divisor)
1593                 lt->divisor = 0;
1594         }
1595
1596         break;
1597
1598     case LFT_HTTP_SENT_STATUS_CODE_OLD_30:
1599         debugs(46, 0, "WARNING: the \"Hs\" formating code is deprecated use the \">Hs\" instead");
1600         lt->type = LFT_HTTP_SENT_STATUS_CODE;
1601         break;
1602     default:
1603         break;
1604     }
1605
1606     return (cur - def);
1607 }
1608
1609 int
1610 accessLogParseLogFormat(logformat_token ** fmt, char *def)
1611 {
1612     char *cur, *eos;
1613     logformat_token *new_lt, *last_lt;
1614     enum log_quote quote = LOG_QUOTE_NONE;
1615
1616     debugs(46, 2, "accessLogParseLogFormat: got definition '" << def << "'");
1617
1618     /* very inefficent parser, but who cares, this needs to be simple */
1619     /* First off, let's tokenize, we'll optimize in a second pass.
1620      * A token can either be a %-prefixed sequence (usually a dynamic
1621      * token but it can be an escaped sequence), or a string. */
1622     cur = def;
1623     eos = def + strlen(def);
1624     *fmt = new_lt = last_lt = (logformat_token *)xmalloc(sizeof(logformat_token));
1625     cur += accessLogGetNewLogFormatToken(new_lt, cur, &quote);
1626
1627     while (cur < eos) {
1628         new_lt = (logformat_token *)xmalloc(sizeof(logformat_token));
1629         last_lt->next = new_lt;
1630         last_lt = new_lt;
1631         cur += accessLogGetNewLogFormatToken(new_lt, cur, &quote);
1632     }
1633
1634     return 1;
1635 }
1636
1637 void
1638 accessLogDumpLogFormat(StoreEntry * entry, const char *name, logformat * definitions)
1639 {
1640     logformat_token *t;
1641     logformat *format;
1642
1643     struct logformat_token_table_entry *te;
1644     debugs(46, 4, "accessLogDumpLogFormat called");
1645
1646     for (format = definitions; format; format = format->next) {
1647         debugs(46, 3, "Dumping logformat definition for " << format->name);
1648         storeAppendPrintf(entry, "logformat %s ", format->name);
1649
1650         for (t = format->format; t; t = t->next) {
1651             if (t->type == LFT_STRING)
1652                 storeAppendPrintf(entry, "%s", t->data.string);
1653             else {
1654                 char argbuf[256];
1655                 char *arg = NULL;
1656                 logformat_bcode_t type = t->type;
1657
1658                 switch (type) {
1659                     /* special cases */
1660
1661                 case LFT_STRING:
1662                     break;
1663 #if USE_ADAPTATION
1664                 case LFT_ADAPTATION_LAST_HEADER_ELEM:
1665 #endif
1666 #if ICAP_CLIENT
1667                 case LFT_ICAP_REQ_HEADER_ELEM:
1668                 case LFT_ICAP_REP_HEADER_ELEM:
1669 #endif
1670                 case LFT_REQUEST_HEADER_ELEM:
1671                 case LFT_ADAPTED_REQUEST_HEADER_ELEM:
1672                 case LFT_REPLY_HEADER_ELEM:
1673
1674                     if (t->data.header.separator != ',')
1675                         snprintf(argbuf, sizeof(argbuf), "%s:%c%s", t->data.header.header, t->data.header.separator, t->data.header.element);
1676                     else
1677                         snprintf(argbuf, sizeof(argbuf), "%s:%s", t->data.header.header, t->data.header.element);
1678
1679                     arg = argbuf;
1680
1681                     switch (type) {
1682                     case LFT_REQUEST_HEADER_ELEM:
1683                         type = LFT_REQUEST_HEADER;
1684                         break;
1685                     case LFT_ADAPTED_REQUEST_HEADER_ELEM:
1686                         type = LFT_ADAPTED_REQUEST_HEADER;
1687                         break;
1688                     case LFT_REPLY_HEADER_ELEM:
1689                         type = LFT_REPLY_HEADER;
1690                         break;
1691 #if USE_ADAPTATION
1692                     case LFT_ADAPTATION_LAST_HEADER_ELEM:
1693                         type = LFT_ADAPTATION_LAST_HEADER;
1694                         break;
1695 #endif
1696 #if ICAP_CLIENT
1697                     case LFT_ICAP_REQ_HEADER_ELEM:
1698                         type = LFT_ICAP_REQ_HEADER;
1699                         break;
1700                     case LFT_ICAP_REP_HEADER_ELEM:
1701                         type = LFT_ICAP_REP_HEADER;
1702                         break;
1703 #endif
1704                     default:
1705                         break;
1706                     }
1707
1708                     break;
1709
1710                 case LFT_REQUEST_ALL_HEADERS:
1711                 case LFT_ADAPTED_REQUEST_ALL_HEADERS:
1712                 case LFT_REPLY_ALL_HEADERS:
1713
1714 #if USE_ADAPTATION
1715                 case LFT_ADAPTATION_LAST_ALL_HEADERS:
1716 #endif
1717 #if ICAP_CLIENT
1718                 case LFT_ICAP_REQ_ALL_HEADERS:
1719                 case LFT_ICAP_REP_ALL_HEADERS:
1720 #endif
1721
1722                     switch (type) {
1723                     case LFT_REQUEST_ALL_HEADERS:
1724                         type = LFT_REQUEST_HEADER;
1725                         break;
1726                     case LFT_ADAPTED_REQUEST_ALL_HEADERS:
1727                         type = LFT_ADAPTED_REQUEST_HEADER;
1728                         break;
1729                     case LFT_REPLY_ALL_HEADERS:
1730                         type = LFT_REPLY_HEADER;
1731                         break;
1732 #if USE_ADAPTATION
1733                     case LFT_ADAPTATION_LAST_ALL_HEADERS:
1734                         type = LFT_ADAPTATION_LAST_HEADER;
1735                         break;
1736 #endif
1737 #if ICAP_CLIENT
1738                     case LFT_ICAP_REQ_ALL_HEADERS:
1739                         type = LFT_ICAP_REQ_HEADER;
1740                         break;
1741                     case LFT_ICAP_REP_ALL_HEADERS:
1742                         type = LFT_ICAP_REP_HEADER;
1743                         break;
1744 #endif
1745                     default:
1746                         break;
1747                     }
1748
1749                     break;
1750
1751                 default:
1752                     if (t->data.string)
1753                         arg = t->data.string;
1754
1755                     break;
1756                 }
1757
1758                 entry->append("%", 1);
1759
1760                 switch (t->quote) {
1761
1762                 case LOG_QUOTE_QUOTES:
1763                     entry->append("\"", 1);
1764                     break;
1765
1766                 case LOG_QUOTE_BRAKETS:
1767                     entry->append("[", 1);
1768                     break;
1769
1770                 case LOG_QUOTE_URL:
1771                     entry->append("#", 1);
1772                     break;
1773
1774                 case LOG_QUOTE_RAW:
1775                     entry->append("'", 1);
1776                     break;
1777
1778                 case LOG_QUOTE_NONE:
1779                     break;
1780                 }
1781
1782                 if (t->left)
1783                     entry->append("-", 1);
1784
1785                 if (t->zero)
1786                     entry->append("0", 1);
1787
1788                 if (t->width)
1789                     storeAppendPrintf(entry, "%d", (int) t->width);
1790
1791                 if (t->precision)
1792                     storeAppendPrintf(entry, ".%d", (int) t->precision);
1793
1794                 if (arg)
1795                     storeAppendPrintf(entry, "{%s}", arg);
1796
1797                 for (te = logformat_token_table; te->config != NULL; te++) {
1798                     if (te->token_type == type) {
1799                         storeAppendPrintf(entry, "%s", te->config);
1800                         break;
1801                     }
1802                 }
1803
1804                 if (t->space)
1805                     entry->append(" ", 1);
1806
1807                 assert(te->config != NULL);
1808             }
1809         }
1810
1811         entry->append("\n", 1);
1812     }
1813
1814 }
1815
1816 void
1817 accessLogFreeLogFormat(logformat_token ** tokens)
1818 {
1819     while (*tokens) {
1820         logformat_token *token = *tokens;
1821         *tokens = token->next;
1822         safe_free(token->data.string);
1823         xfree(token);
1824     }
1825 }
1826
1827 static void
1828 accessLogSquid(AccessLogEntry * al, Logfile * logfile)
1829 {
1830     const char *client = NULL;
1831     const char *user = NULL;
1832     char buf[MAX_IPSTRLEN];
1833
1834     if (Config.onoff.log_fqdn) {
1835         client = fqdncache_gethostbyaddr(al->cache.caddr, FQDN_LOOKUP_IF_MISS);
1836     }
1837
1838     if (client == NULL) {
1839         client = al->cache.caddr.NtoA(buf,MAX_IPSTRLEN);
1840     }
1841
1842     user = accessLogFormatName(al->cache.authuser);
1843
1844     if (!user)
1845         user = accessLogFormatName(al->cache.extuser);
1846
1847 #if USE_SSL
1848
1849     if (!user)
1850         user = accessLogFormatName(al->cache.ssluser);
1851
1852 #endif
1853
1854     if (!user)
1855         user = accessLogFormatName(al->cache.rfc931);
1856
1857     if (user && !*user)
1858         safe_free(user);
1859
1860     if (!Config.onoff.log_mime_hdrs) {
1861         logfilePrintf(logfile, "%9ld.%03d %6d %s %s%s/%03d %"PRId64" %s %s %s %s%s/%s %s\n",
1862                       (long int) current_time.tv_sec,
1863                       (int) current_time.tv_usec / 1000,
1864                       al->cache.msec,
1865                       client,
1866                       log_tags[al->cache.code],
1867                       al->http.statusSfx(),
1868                       al->http.code,
1869                       al->cache.replySize,
1870                       al->_private.method_str,
1871                       al->url,
1872                       user ? user : dash_str,
1873                       al->hier.ping.timedout ? "TIMEOUT_" : "",
1874                       hier_code_str[al->hier.code],
1875                       al->hier.host,
1876                       al->http.content_type);
1877     } else {
1878         char *ereq = log_quote(al->headers.request);
1879         char *erep = log_quote(al->headers.reply);
1880         logfilePrintf(logfile, "%9ld.%03d %6d %s %s%s/%03d %"PRId64" %s %s %s %s%s/%s %s [%s] [%s]\n",
1881                       (long int) current_time.tv_sec,
1882                       (int) current_time.tv_usec / 1000,
1883                       al->cache.msec,
1884                       client,
1885                       log_tags[al->cache.code],
1886                       al->http.statusSfx(),
1887                       al->http.code,
1888                       al->cache.replySize,
1889                       al->_private.method_str,
1890                       al->url,
1891                       user ? user : dash_str,
1892                       al->hier.ping.timedout ? "TIMEOUT_" : "",
1893                       hier_code_str[al->hier.code],
1894                       al->hier.host,
1895                       al->http.content_type,
1896                       ereq,
1897                       erep);
1898         safe_free(ereq);
1899         safe_free(erep);
1900     }
1901     safe_free(user);
1902 }
1903
1904 static void
1905 accessLogCommon(AccessLogEntry * al, Logfile * logfile)
1906 {
1907     const char *client = NULL;
1908     char *user1 = NULL, *user2 = NULL;
1909     char buf[MAX_IPSTRLEN];
1910
1911     if (Config.onoff.log_fqdn) {
1912         client = fqdncache_gethostbyaddr(al->cache.caddr, 0);
1913     }
1914
1915     if (client == NULL) {
1916         client = al->cache.caddr.NtoA(buf,MAX_IPSTRLEN);
1917     }
1918
1919     user1 = accessLogFormatName(al->cache.authuser);
1920
1921     user2 = accessLogFormatName(al->cache.rfc931);
1922
1923     logfilePrintf(logfile, "%s %s %s [%s] \"%s %s HTTP/%d.%d\" %d %"PRId64" %s%s:%s%s",
1924                   client,
1925                   user2 ? user2 : dash_str,
1926                   user1 ? user1 : dash_str,
1927                   mkhttpdlogtime(&squid_curtime),
1928                   al->_private.method_str,
1929                   al->url,
1930                   al->http.version.major, al->http.version.minor,
1931                   al->http.code,
1932                   al->cache.replySize,
1933                   log_tags[al->cache.code],
1934                   al->http.statusSfx(),
1935                   hier_code_str[al->hier.code],
1936                   (Config.onoff.log_mime_hdrs?"":"\n"));
1937
1938     safe_free(user1);
1939
1940     safe_free(user2);
1941
1942     if (Config.onoff.log_mime_hdrs) {
1943         char *ereq = log_quote(al->headers.request);
1944         char *erep = log_quote(al->headers.reply);
1945         logfilePrintf(logfile, " [%s] [%s]\n", ereq, erep);
1946         safe_free(ereq);
1947         safe_free(erep);
1948     }
1949 }
1950
1951 #if ICAP_CLIENT
1952 static void
1953 accessLogICAPSquid(AccessLogEntry * al, Logfile * logfile)
1954 {
1955     const char *client = NULL;
1956     const char *user = NULL;
1957     char tmp[MAX_IPSTRLEN], clientbuf[MAX_IPSTRLEN];
1958
1959     if (al->cache.caddr.IsAnyAddr()) { // ICAP OPTIONS xactions lack client
1960         client = "-";
1961     } else {
1962         if (Config.onoff.log_fqdn)
1963             client = fqdncache_gethostbyaddr(al->cache.caddr, FQDN_LOOKUP_IF_MISS);
1964         if (!client)
1965             client = al->cache.caddr.NtoA(clientbuf, MAX_IPSTRLEN);
1966     }
1967
1968     user = accessLogFormatName(al->cache.authuser);
1969
1970     if (!user)
1971         user = accessLogFormatName(al->cache.extuser);
1972
1973 #if USE_SSL
1974
1975     if (!user)
1976         user = accessLogFormatName(al->cache.ssluser);
1977
1978 #endif
1979
1980     if (!user)
1981         user = accessLogFormatName(al->cache.rfc931);
1982
1983     if (user && !*user)
1984         safe_free(user);
1985
1986     logfilePrintf(logfile, "%9ld.%03d %6d %s -/%03d %"PRId64" %s %s %s -/%s -\n",
1987                   (long int) current_time.tv_sec,
1988                   (int) current_time.tv_usec / 1000,
1989
1990                   al->icap.trTime,
1991                   client,
1992
1993                   al->icap.resStatus,
1994                   al->icap.bytesRead,
1995                   Adaptation::Icap::ICAP::methodStr(al->icap.reqMethod),
1996                   al->icap.reqUri.termedBuf(),
1997                   user ? user : dash_str,
1998                   al->icap.hostAddr.NtoA(tmp, MAX_IPSTRLEN));
1999     safe_free(user);
2000 }
2001 #endif
2002
2003 void
2004 accessLogLogTo(customlog* log, AccessLogEntry * al, ACLChecklist * checklist)
2005 {
2006
2007     if (al->url == NULL)
2008         al->url = dash_str;
2009
2010     if (!al->http.content_type || *al->http.content_type == '\0')
2011         al->http.content_type = dash_str;
2012
2013     if (al->icp.opcode)
2014         al->_private.method_str = icp_opcode_str[al->icp.opcode];
2015     else if (al->htcp.opcode)
2016         al->_private.method_str = al->htcp.opcode;
2017     else
2018         al->_private.method_str = RequestMethodStr(al->http.method);
2019
2020     if (al->hier.host[0] == '\0')
2021         xstrncpy(al->hier.host, dash_str, SQUIDHOSTNAMELEN);
2022
2023     for (; log; log = log->next) {
2024         if (checklist && log->aclList && !checklist->matchAclListFast(log->aclList))
2025             continue;
2026
2027         if (log->logfile) {
2028             logfileLineStart(log->logfile);
2029
2030             switch (log->type) {
2031
2032             case CLF_AUTO:
2033                 if (Config.onoff.common_log)
2034                     accessLogCommon(al, log->logfile);
2035                 else
2036                     accessLogSquid(al, log->logfile);
2037                 break;
2038
2039             case CLF_SQUID:
2040                 accessLogSquid(al, log->logfile);
2041                 break;
2042
2043             case CLF_COMMON:
2044                 accessLogCommon(al, log->logfile);
2045                 break;
2046
2047             case CLF_CUSTOM:
2048                 accessLogCustom(al, log);
2049                 break;
2050
2051 #if ICAP_CLIENT
2052             case CLF_ICAP_SQUID:
2053                 accessLogICAPSquid(al, log->logfile);
2054                 break;
2055 #endif
2056
2057             case CLF_NONE:
2058                 return; // abort!
2059
2060             default:
2061                 fatalf("Unknown log format %d\n", log->type);
2062                 break;
2063             }
2064
2065             logfileLineEnd(log->logfile);
2066         }
2067
2068         // NP:  WTF?  if _any_ log line has no checklist ignore the following ones?
2069         if (!checklist)
2070             break;
2071     }
2072 }
2073
2074 void
2075 accessLogLog(AccessLogEntry * al, ACLChecklist * checklist)
2076 {
2077     if (LogfileStatus != LOG_ENABLE)
2078         return;
2079
2080     accessLogLogTo(Config.Log.accesslogs, al, checklist);
2081 #if MULTICAST_MISS_STREAM
2082
2083     if (al->cache.code != LOG_TCP_MISS)
2084         (void) 0;
2085     else if (al->http.method != METHOD_GET)
2086         (void) 0;
2087     else if (mcast_miss_fd < 0)
2088         (void) 0;
2089     else {
2090         unsigned int ibuf[365];
2091         size_t isize;
2092         xstrncpy((char *) ibuf, al->url, 364 * sizeof(int));
2093         isize = ((strlen(al->url) + 8) / 8) * 2;
2094
2095         if (isize > 364)
2096             isize = 364;
2097
2098         mcast_encode((unsigned int *) ibuf, isize,
2099                      (const unsigned int *) Config.mcast_miss.encode_key);
2100
2101         comm_udp_sendto(mcast_miss_fd,
2102                         &mcast_miss_to, sizeof(mcast_miss_to),
2103                         ibuf, isize * sizeof(int));
2104     }
2105
2106 #endif
2107 }
2108
2109 void
2110 accessLogRotate(void)
2111 {
2112     customlog *log;
2113 #if USE_FORW_VIA_DB
2114
2115     fvdbClear();
2116 #endif
2117
2118     for (log = Config.Log.accesslogs; log; log = log->next) {
2119         if (log->logfile) {
2120             logfileRotate(log->logfile);
2121         }
2122     }
2123
2124 #if HEADERS_LOG
2125
2126     logfileRotate(headerslog);
2127
2128 #endif
2129 }
2130
2131 void
2132 accessLogClose(void)
2133 {
2134     customlog *log;
2135
2136     for (log = Config.Log.accesslogs; log; log = log->next) {
2137         if (log->logfile) {
2138             logfileClose(log->logfile);
2139             log->logfile = NULL;
2140         }
2141     }
2142
2143 #if HEADERS_LOG
2144
2145     logfileClose(headerslog);
2146
2147     headerslog = NULL;
2148
2149 #endif
2150 }
2151
2152 HierarchyLogEntry::HierarchyLogEntry() :
2153         code(HIER_NONE),
2154         cd_lookup(LOOKUP_NONE),
2155         n_choices(0),
2156         n_ichoices(0),
2157         peer_reply_status(HTTP_STATUS_NONE),
2158         peer_response_time(-1),
2159         total_response_time(-1),
2160         peer_local_port(0),
2161         bodyBytesRead(-1)
2162 {
2163     memset(host, '\0', SQUIDHOSTNAMELEN);
2164     memset(cd_host, '\0', SQUIDHOSTNAMELEN);
2165
2166     peer_select_start.tv_sec =0;
2167     peer_select_start.tv_usec =0;
2168
2169     store_complete_stop.tv_sec =0;
2170     store_complete_stop.tv_usec =0;
2171
2172     peer_http_request_sent.tv_sec = 0;
2173     peer_http_request_sent.tv_usec = 0;
2174
2175     first_conn_start.tv_sec = 0;
2176     first_conn_start.tv_usec = 0;
2177 }
2178
2179 void
2180 hierarchyNote(HierarchyLogEntry * hl,
2181               hier_code code,
2182               const char *cache_peer)
2183 {
2184     assert(hl != NULL);
2185     hl->code = code;
2186     xstrncpy(hl->host, cache_peer, SQUIDHOSTNAMELEN);
2187 }
2188
2189 static void
2190 accessLogRegisterWithCacheManager(void)
2191 {
2192 #if USE_FORW_VIA_DB
2193     fvdbRegisterWithCacheManager();
2194 #endif
2195 }
2196
2197 void
2198 accessLogInit(void)
2199 {
2200     customlog *log;
2201
2202     accessLogRegisterWithCacheManager();
2203
2204     assert(sizeof(log_tags) == (LOG_TYPE_MAX + 1) * sizeof(char *));
2205
2206 #if USE_ADAPTATION
2207     alLogformatHasAdaptToken = false;
2208 #endif
2209 #if ICAP_CLIENT
2210     alLogformatHasIcapToken = false;
2211 #endif
2212
2213     for (log = Config.Log.accesslogs; log; log = log->next) {
2214         if (log->type == CLF_NONE)
2215             continue;
2216
2217         log->logfile = logfileOpen(log->filename, MAX_URL << 2, 1);
2218
2219         LogfileStatus = LOG_ENABLE;
2220
2221 #if USE_ADAPTATION
2222         for (logformat_token * curr_token = (log->logFormat?log->logFormat->format:NULL); curr_token; curr_token = curr_token->next) {
2223             if (curr_token->type == LTF_ADAPTATION_SUM_XACT_TIMES ||
2224                     curr_token->type == LTF_ADAPTATION_ALL_XACT_TIMES ||
2225                     curr_token->type == LFT_ADAPTATION_LAST_HEADER ||
2226                     curr_token->type == LFT_ADAPTATION_LAST_HEADER_ELEM ||
2227                     curr_token->type == LFT_ADAPTATION_LAST_ALL_HEADERS) {
2228                 alLogformatHasAdaptToken = true;
2229             }
2230 #if ICAP_CLIENT
2231             if (curr_token->type == LFT_ICAP_TOTAL_TIME) {
2232                 alLogformatHasIcapToken = true;
2233             }
2234 #endif
2235         }
2236 #endif
2237     }
2238
2239 #if HEADERS_LOG
2240
2241     headerslog = logfileOpen("/usr/local/squid/logs/headers.log", 512);
2242
2243     assert(NULL != headerslog);
2244
2245 #endif
2246 #if MULTICAST_MISS_STREAM
2247
2248     if (Config.mcast_miss.addr.s_addr != no_addr.s_addr) {
2249         memset(&mcast_miss_to, '\0', sizeof(mcast_miss_to));
2250         mcast_miss_to.sin_family = AF_INET;
2251         mcast_miss_to.sin_port = htons(Config.mcast_miss.port);
2252         mcast_miss_to.sin_addr.s_addr = Config.mcast_miss.addr.s_addr;
2253         mcast_miss_fd = comm_open(SOCK_DGRAM,
2254                                   IPPROTO_UDP,
2255                                   Config.Addrs.udp_incoming,
2256                                   Config.mcast_miss.port,
2257                                   COMM_NONBLOCKING,
2258                                   "Multicast Miss Stream");
2259
2260         if (mcast_miss_fd < 0)
2261             fatal("Cannot open Multicast Miss Stream Socket");
2262
2263         debugs(46, 1, "Multicast Miss Stream Socket opened on FD " << mcast_miss_fd);
2264
2265         mcastSetTtl(mcast_miss_fd, Config.mcast_miss.ttl);
2266
2267         if (strlen(Config.mcast_miss.encode_key) < 16)
2268             fatal("mcast_encode_key is too short, must be 16 characters");
2269     }
2270
2271 #endif
2272 #if USE_FORW_VIA_DB
2273
2274     fvdbInit();
2275
2276 #endif
2277 }
2278
2279 const char *
2280 accessLogTime(time_t t)
2281 {
2282
2283     struct tm *tm;
2284     static char buf[128];
2285     static time_t last_t = 0;
2286
2287     if (t != last_t) {
2288         tm = localtime(&t);
2289         strftime(buf, 127, "%Y/%m/%d %H:%M:%S", tm);
2290         last_t = t;
2291     }
2292
2293     return buf;
2294 }
2295
2296
2297 #if USE_FORW_VIA_DB
2298
2299 static void
2300 fvdbInit(void)
2301 {
2302     via_table = hash_create((HASHCMP *) strcmp, 977, hash4);
2303     forw_table = hash_create((HASHCMP *) strcmp, 977, hash4);
2304 }
2305
2306 static void
2307 fvdbRegisterWithCacheManager(void)
2308 {
2309     Mgr::RegisterAction("via_headers", "Via Request Headers", fvdbDumpVia, 0, 1);
2310     Mgr::RegisterAction("forw_headers", "X-Forwarded-For Request Headers",
2311                         fvdbDumpForw, 0, 1);
2312 }
2313
2314 static void
2315 fvdbCount(hash_table * hash, const char *key)
2316 {
2317     fvdb_entry *fv;
2318
2319     if (NULL == hash)
2320         return;
2321
2322     fv = (fvdb_entry *)hash_lookup(hash, key);
2323
2324     if (NULL == fv) {
2325         fv = static_cast <fvdb_entry *>(xcalloc(1, sizeof(fvdb_entry)));
2326         fv->hash.key = xstrdup(key);
2327         hash_join(hash, &fv->hash);
2328     }
2329
2330     fv->n++;
2331 }
2332
2333 void
2334 fvdbCountVia(const char *key)
2335 {
2336     fvdbCount(via_table, key);
2337 }
2338
2339 void
2340 fvdbCountForw(const char *key)
2341 {
2342     fvdbCount(forw_table, key);
2343 }
2344
2345 static void
2346 fvdbDumpTable(StoreEntry * e, hash_table * hash)
2347 {
2348     hash_link *h;
2349     fvdb_entry *fv;
2350
2351     if (hash == NULL)
2352         return;
2353
2354     hash_first(hash);
2355
2356     while ((h = hash_next(hash))) {
2357         fv = (fvdb_entry *) h;
2358         storeAppendPrintf(e, "%9d %s\n", fv->n, hashKeyStr(&fv->hash));
2359     }
2360 }
2361
2362 static void
2363 fvdbDumpVia(StoreEntry * e)
2364 {
2365     fvdbDumpTable(e, via_table);
2366 }
2367
2368 static void
2369 fvdbDumpForw(StoreEntry * e)
2370 {
2371     fvdbDumpTable(e, forw_table);
2372 }
2373
2374 static
2375 void
2376 fvdbFreeEntry(void *data)
2377 {
2378     fvdb_entry *fv = static_cast <fvdb_entry *>(data);
2379     xfree(fv->hash.key);
2380     xfree(fv);
2381 }
2382
2383 static void
2384 fvdbClear(void)
2385 {
2386     hashFreeItems(via_table, fvdbFreeEntry);
2387     hashFreeMemory(via_table);
2388     via_table = hash_create((HASHCMP *) strcmp, 977, hash4);
2389     hashFreeItems(forw_table, fvdbFreeEntry);
2390     hashFreeMemory(forw_table);
2391     forw_table = hash_create((HASHCMP *) strcmp, 977, hash4);
2392 }
2393
2394 #endif
2395
2396 #if MULTICAST_MISS_STREAM
2397 /*
2398  * From http://www.io.com/~paulhart/game/algorithms/tea.html
2399  *
2400  * size of 'ibuf' must be a multiple of 2.
2401  * size of 'key' must be 4.
2402  * 'ibuf' is modified in place, encrypted data is written in
2403  * network byte order.
2404  */
2405 static void
2406 mcast_encode(unsigned int *ibuf, size_t isize, const unsigned int *key)
2407 {
2408     unsigned int y;
2409     unsigned int z;
2410     unsigned int sum;
2411     const unsigned int delta = 0x9e3779b9;
2412     unsigned int n = 32;
2413     const unsigned int k0 = htonl(key[0]);
2414     const unsigned int k1 = htonl(key[1]);
2415     const unsigned int k2 = htonl(key[2]);
2416     const unsigned int k3 = htonl(key[3]);
2417     int i;
2418
2419     for (i = 0; i < isize; i += 2) {
2420         y = htonl(ibuf[i]);
2421         z = htonl(ibuf[i + 1]);
2422         sum = 0;
2423
2424         for (n = 32; n; n--) {
2425             sum += delta;
2426             y += (z << 4) + (k0 ^ z) + (sum ^ (z >> 5)) + k1;
2427             z += (y << 4) + (k2 ^ y) + (sum ^ (y >> 5)) + k3;
2428         }
2429
2430         ibuf[i] = htonl(y);
2431         ibuf[i + 1] = htonl(z);
2432     }
2433 }
2434
2435 #endif
2436
2437 #if HEADERS_LOG
2438 void
2439 headersLog(int cs, int pq, const HttpRequestMethod& method, void *data)
2440 {
2441     HttpReply *rep;
2442     HttpRequest *req;
2443     unsigned short magic = 0;
2444     unsigned char M = (unsigned char) m;
2445     unsigned short S;
2446     char *hmask;
2447     int ccmask = 0;
2448
2449     if (0 == pq) {
2450         /* reply */
2451         rep = data;
2452         req = NULL;
2453         magic = 0x0050;
2454         hmask = rep->header.mask;
2455
2456         if (rep->cache_control)
2457             ccmask = rep->cache_control->mask;
2458     } else {
2459         /* request */
2460         req = data;
2461         rep = NULL;
2462         magic = 0x0051;
2463         hmask = req->header.mask;
2464
2465         if (req->cache_control)
2466             ccmask = req->cache_control->mask;
2467     }
2468
2469     if (0 == cs) {
2470         /* client */
2471         magic |= 0x4300;
2472     } else {
2473         /* server */
2474         magic |= 0x5300;
2475     }
2476
2477     magic = htons(magic);
2478     ccmask = htonl(ccmask);
2479
2480     if (0 == pq)
2481         S = (unsigned short) rep->sline.status;
2482     else
2483         S = (unsigned short) HTTP_STATUS_NONE;
2484
2485     logfileWrite(headerslog, &magic, sizeof(magic));
2486     logfileWrite(headerslog, &M, sizeof(M));
2487     logfileWrite(headerslog, &S, sizeof(S));
2488     logfileWrite(headerslog, hmask, sizeof(HttpHeaderMask));
2489     logfileWrite(headerslog, &ccmask, sizeof(int));
2490 }
2491
2492 #endif
2493
2494 void
2495 accessLogFreeMemory(AccessLogEntry * aLogEntry)
2496 {
2497     safe_free(aLogEntry->headers.request);
2498
2499 #if ICAP_CLIENT
2500     safe_free(aLogEntry->headers.adapt_last);
2501 #endif
2502
2503     safe_free(aLogEntry->headers.reply);
2504     safe_free(aLogEntry->cache.authuser);
2505
2506     safe_free(aLogEntry->headers.adapted_request);
2507     HTTPMSGUNLOCK(aLogEntry->adapted_request);
2508
2509     HTTPMSGUNLOCK(aLogEntry->reply);
2510     HTTPMSGUNLOCK(aLogEntry->request);
2511 #if ICAP_CLIENT
2512     HTTPMSGUNLOCK(aLogEntry->icap.reply);
2513     HTTPMSGUNLOCK(aLogEntry->icap.request);
2514 #endif
2515 }
2516
2517 int
2518 logTypeIsATcpHit(log_type code)
2519 {
2520     /* this should be a bitmap for better optimization */
2521
2522     if (code == LOG_TCP_HIT)
2523         return 1;
2524
2525     if (code == LOG_TCP_IMS_HIT)
2526         return 1;
2527
2528     if (code == LOG_TCP_REFRESH_FAIL_OLD)
2529         return 1;
2530
2531     if (code == LOG_TCP_REFRESH_UNMODIFIED)
2532         return 1;
2533
2534     if (code == LOG_TCP_NEGATIVE_HIT)
2535         return 1;
2536
2537     if (code == LOG_TCP_MEM_HIT)
2538         return 1;
2539
2540     if (code == LOG_TCP_OFFLINE_HIT)
2541         return 1;
2542
2543     return 0;
2544 }