src/format/Format.cc

   1 /*
   2  * Copyright (C) 1996-2014 The Squid Software Foundation and contributors
   3  *
   4  * Squid software is distributed under GPLv2+ license and includes
   5  * contributions from numerous individuals and organizations.
   6  * Please see the COPYING and CONTRIBUTORS files for details.
   7  */
   8
   9 #include "squid.h"
  10 #include "AccessLogEntry.h"
  11 #include "client_side.h"
  12 #include "comm/Connection.h"
  13 #include "err_detail_type.h"
  14 #include "errorpage.h"
  15 #include "fde.h"
  16 #include "format/Format.h"
  17 #include "format/Quoting.h"
  18 #include "format/Token.h"
  19 #include "fqdncache.h"
  20 #include "HttpRequest.h"
  21 #include "MemBuf.h"
  22 #include "rfc1738.h"
  23 #include "SquidTime.h"
  24 #include "Store.h"
  25 #include "URL.h"
  26 #if USE_OPENSSL
  27 #include "ssl/ErrorDetail.h"
  28 #include "ssl/ServerBump.h"
  29 #endif
  30
  31 /// Convert a string to NULL pointer if it is ""
  32 #define strOrNull(s) ((s)==NULL||(s)[0]=='\0'?NULL:(s))
  33
  34 Format::Format::Format(const char *n) :
  35         format(NULL),
  36         next(NULL)
  37 {
  38     name = xstrdup(n);
  39 }
  40
  41 Format::Format::~Format()
  42 {
  43     // erase the list without consuming stack space
  44     while (next) {
  45         // unlink the next entry for deletion
  46         Format *temp = next;
  47         next = temp->next;
  48         temp->next = NULL;
  49         delete temp;
  50     }
  51
  52     // remove locals
  53     xfree(name);
  54     delete format;
  55 }
  56
  57 bool
  58 Format::Format::parse(const char *def)
  59 {
  60     const char *cur, *eos;
  61     Token *new_lt, *last_lt;
  62     enum Quoting quote = LOG_QUOTE_NONE;
  63
  64     debugs(46, 2, HERE << "got definition '" << def << "'");
  65
  66     if (format) {
  67         debugs(46, DBG_IMPORTANT, "WARNING: existing format for '" << name << " " << def << "'");
  68         return false;
  69     }
  70
  71     /* very inefficent parser, but who cares, this needs to be simple */
  72     /* First off, let's tokenize, we'll optimize in a second pass.
  73      * A token can either be a %-prefixed sequence (usually a dynamic
  74      * token but it can be an escaped sequence), or a string. */
  75     cur = def;
  76     eos = def + strlen(def);
  77     format = new_lt = last_lt = new Token;
  78     cur += new_lt->parse(cur, &quote);
  79
  80     while (cur < eos) {
  81         new_lt = new Token;
  82         last_lt->next = new_lt;
  83         last_lt = new_lt;
  84         cur += new_lt->parse(cur, &quote);
  85     }
  86
  87     return true;
  88 }
  89
  90 void
  91 Format::Format::dump(StoreEntry * entry, const char *directiveName)
  92 {
  93     debugs(46, 4, HERE);
  94
  95     // loop rather than recursing to conserve stack space.
  96     for (Format *fmt = this; fmt; fmt = fmt->next) {
  97         debugs(46, 3, HERE << "Dumping format definition for " << fmt->name);
  98         storeAppendPrintf(entry, "%s %s ", directiveName, fmt->name);
  99
 100         for (Token *t = fmt->format; t; t = t->next) {
 101             if (t->type == LFT_STRING)
 102                 storeAppendPrintf(entry, "%s", t->data.string);
 103             else {
 104                 char argbuf[256];
 105                 char *arg = NULL;
 106                 ByteCode_t type = t->type;
 107
 108                 switch (type) {
 109                     /* special cases */
 110
 111                 case LFT_STRING:
 112                     break;
 113 #if USE_ADAPTATION
 114                 case LFT_ADAPTATION_LAST_HEADER_ELEM:
 115 #endif
 116 #if ICAP_CLIENT
 117                 case LFT_ICAP_REQ_HEADER_ELEM:
 118                 case LFT_ICAP_REP_HEADER_ELEM:
 119 #endif
 120                 case LFT_REQUEST_HEADER_ELEM:
 121                 case LFT_ADAPTED_REQUEST_HEADER_ELEM:
 122                 case LFT_REPLY_HEADER_ELEM:
 123
 124                     if (t->data.header.separator != ',')
 125                         snprintf(argbuf, sizeof(argbuf), "%s:%c%s", t->data.header.header, t->data.header.separator, t->data.header.element);
 126                     else
 127                         snprintf(argbuf, sizeof(argbuf), "%s:%s", t->data.header.header, t->data.header.element);
 128
 129                     arg = argbuf;
 130
 131                     switch (type) {
 132                     case LFT_REQUEST_HEADER_ELEM:
 133                         type = LFT_REQUEST_HEADER_ELEM; // XXX: remove _ELEM?
 134                         break;
 135                     case LFT_ADAPTED_REQUEST_HEADER_ELEM:
 136                         type = LFT_ADAPTED_REQUEST_HEADER_ELEM; // XXX: remove _ELEM?
 137                         break;
 138                     case LFT_REPLY_HEADER_ELEM:
 139                         type = LFT_REPLY_HEADER_ELEM; // XXX: remove _ELEM?
 140                         break;
 141 #if USE_ADAPTATION
 142                     case LFT_ADAPTATION_LAST_HEADER_ELEM:
 143                         type = LFT_ADAPTATION_LAST_HEADER;
 144                         break;
 145 #endif
 146 #if ICAP_CLIENT
 147                     case LFT_ICAP_REQ_HEADER_ELEM:
 148                         type = LFT_ICAP_REQ_HEADER;
 149                         break;
 150                     case LFT_ICAP_REP_HEADER_ELEM:
 151                         type = LFT_ICAP_REP_HEADER;
 152                         break;
 153 #endif
 154                     default:
 155                         break;
 156                     }
 157
 158                     break;
 159
 160                 case LFT_REQUEST_ALL_HEADERS:
 161                 case LFT_ADAPTED_REQUEST_ALL_HEADERS:
 162                 case LFT_REPLY_ALL_HEADERS:
 163
 164 #if USE_ADAPTATION
 165                 case LFT_ADAPTATION_LAST_ALL_HEADERS:
 166 #endif
 167 #if ICAP_CLIENT
 168                 case LFT_ICAP_REQ_ALL_HEADERS:
 169                 case LFT_ICAP_REP_ALL_HEADERS:
 170 #endif
 171
 172                     switch (type) {
 173                     case LFT_REQUEST_ALL_HEADERS:
 174                         type = LFT_REQUEST_HEADER;
 175                         break;
 176                     case LFT_ADAPTED_REQUEST_ALL_HEADERS:
 177                         type = LFT_ADAPTED_REQUEST_HEADER;
 178                         break;
 179                     case LFT_REPLY_ALL_HEADERS:
 180                         type = LFT_REPLY_HEADER;
 181                         break;
 182 #if USE_ADAPTATION
 183                     case LFT_ADAPTATION_LAST_ALL_HEADERS:
 184                         type = LFT_ADAPTATION_LAST_HEADER;
 185                         break;
 186 #endif
 187 #if ICAP_CLIENT
 188                     case LFT_ICAP_REQ_ALL_HEADERS:
 189                         type = LFT_ICAP_REQ_HEADER;
 190                         break;
 191                     case LFT_ICAP_REP_ALL_HEADERS:
 192                         type = LFT_ICAP_REP_HEADER;
 193                         break;
 194 #endif
 195                     default:
 196                         break;
 197                     }
 198
 199                     break;
 200
 201                 default:
 202                     if (t->data.string)
 203                         arg = t->data.string;
 204
 205                     break;
 206                 }
 207
 208                 entry->append("%", 1);
 209
 210                 switch (t->quote) {
 211
 212                 case LOG_QUOTE_QUOTES:
 213                     entry->append("\"", 1);
 214                     break;
 215
 216                 case LOG_QUOTE_MIMEBLOB:
 217                     entry->append("[", 1);
 218                     break;
 219
 220                 case LOG_QUOTE_URL:
 221                     entry->append("#", 1);
 222                     break;
 223
 224                 case LOG_QUOTE_RAW:
 225                     entry->append("'", 1);
 226                     break;
 227
 228                 case LOG_QUOTE_NONE:
 229                     break;
 230                 }
 231
 232                 if (t->left)
 233                     entry->append("-", 1);
 234
 235                 if (t->zero)
 236                     entry->append("0", 1);
 237
 238                 if (t->widthMin >= 0)
 239                     storeAppendPrintf(entry, "%d", t->widthMin);
 240
 241                 if (t->widthMax >= 0)
 242                     storeAppendPrintf(entry, ".%d", t->widthMax);
 243
 244                 if (arg)
 245                     storeAppendPrintf(entry, "{%s}", arg);
 246
 247                 storeAppendPrintf(entry, "%s", t->label);
 248
 249                 if (t->space)
 250                     entry->append(" ", 1);
 251             }
 252         }
 253
 254         entry->append("\n", 1);
 255     }
 256
 257 }
 258
 259 static void
 260 log_quoted_string(const char *str, char *out)
 261 {
 262     char *p = out;
 263
 264     while (*str) {
 265         int l = strcspn(str, "\"\\\r\n\t");
 266         memcpy(p, str, l);
 267         str += l;
 268         p += l;
 269
 270         switch (*str) {
 271
 272         case '\0':
 273             break;
 274
 275         case '\r':
 276             *p = '\\';
 277             ++p;
 278             *p = 'r';
 279             ++p;
 280             ++str;
 281             break;
 282
 283         case '\n':
 284             *p = '\\';
 285             ++p;
 286             *p = 'n';
 287             ++p;
 288             ++str;
 289             break;
 290
 291         case '\t':
 292             *p = '\\';
 293             ++p;
 294             *p = 't';
 295             ++p;
 296             ++str;
 297             break;
 298
 299         default:
 300             *p = '\\';
 301             ++p;
 302             *p = *str;
 303             ++p;
 304             ++str;
 305             break;
 306         }
 307     }
 308
 309     *p = '\0';
 310 }
 311
 312 void
 313 Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logSequenceNumber) const
 314 {
 315     char tmp[1024];
 316     String sb;
 317
 318     for (Token *fmt = format; fmt != NULL; fmt = fmt->next) {   /* for each token */
 319         const char *out = NULL;
 320         int quote = 0;
 321         long int outint = 0;
 322         int doint = 0;
 323         int dofree = 0;
 324         int64_t outoff = 0;
 325         int dooff = 0;
 326
 327         switch (fmt->type) {
 328
 329         case LFT_NONE:
 330             out = "";
 331             break;
 332
 333         case LFT_STRING:
 334             out = fmt->data.string;
 335             break;
 336
 337         case LFT_CLIENT_IP_ADDRESS:
 338             al->getLogClientIp(tmp, sizeof(tmp));
 339             out = tmp;
 340             break;
 341
 342         case LFT_CLIENT_FQDN:
 343             if (al->cache.caddr.isAnyAddr()) // e.g., ICAP OPTIONS lack client
 344                 out = "-";
 345             else
 346                 out = fqdncache_gethostbyaddr(al->cache.caddr, FQDN_LOOKUP_IF_MISS);
 347             if (!out) {
 348                 out = al->cache.caddr.toStr(tmp,1024);
 349             }
 350
 351             break;
 352
 353         case LFT_CLIENT_PORT:
 354             if (al->request) {
 355                 outint = al->request->client_addr.port();
 356                 doint = 1;
 357             }
 358             break;
 359
 360         case LFT_CLIENT_EUI:
 361 #if USE_SQUID_EUI
 362             // TODO make the ACL checklist have a direct link to any TCP details.
 363             if (al->request && al->request->clientConnectionManager.valid() && al->request->clientConnectionManager->clientConnection != NULL) {
 364                 if (al->request->clientConnectionManager->clientConnection->remote.isIPv4())
 365                     al->request->clientConnectionManager->clientConnection->remoteEui48.encode(tmp, 1024);
 366                 else
 367                     al->request->clientConnectionManager->clientConnection->remoteEui64.encode(tmp, 1024);
 368                 out = tmp;
 369             }
 370 #else
 371             out = "-";
 372 #endif
 373             break;
 374
 375         case LFT_SERVER_IP_ADDRESS:
 376             if (al->hier.tcpServer != NULL) {
 377                 out = al->hier.tcpServer->remote.toStr(tmp,sizeof(tmp));
 378             }
 379             break;
 380
 381         case LFT_SERVER_FQDN_OR_PEER_NAME:
 382             out = al->hier.host;
 383             break;
 384
 385         case LFT_SERVER_PORT:
 386             if (al->hier.tcpServer != NULL) {
 387                 outint = al->hier.tcpServer->remote.port();
 388                 doint = 1;
 389             }
 390             break;
 391
 392         case LFT_LOCAL_LISTENING_IP: {
 393             // avoid logging a dash if we have reliable info
 394             const bool interceptedAtKnownPort = al->request ?
 395                                                 (al->request->flags.interceptTproxy ||
 396                                                  al->request->flags.intercepted) && al->cache.port != NULL :
 397                                                 false;
 398             if (interceptedAtKnownPort) {
 399                 const bool portAddressConfigured = !al->cache.port->s.isAnyAddr();
 400                 if (portAddressConfigured)
 401                     out = al->cache.port->s.toStr(tmp, sizeof(tmp));
 402             } else if (al->tcpClient != NULL)
 403                 out = al->tcpClient->local.toStr(tmp, sizeof(tmp));
 404         }
 405         break;
 406
 407         case LFT_CLIENT_LOCAL_IP:
 408             if (al->tcpClient != NULL) {
 409                 out = al->tcpClient->local.toStr(tmp,sizeof(tmp));
 410             }
 411             break;
 412
 413         case LFT_CLIENT_LOCAL_TOS:
 414             if (al->tcpClient != NULL) {
 415                 snprintf(tmp, sizeof(tmp), "0x%x", (uint32_t)al->tcpClient->tos);
 416                 out = tmp;
 417             }
 418             break;
 419
 420         case LFT_CLIENT_LOCAL_NFMARK:
 421             if (al->tcpClient != NULL) {
 422                 snprintf(tmp, sizeof(tmp), "0x%x", al->tcpClient->nfmark);
 423                 out = tmp;
 424             }
 425             break;
 426
 427         case LFT_LOCAL_LISTENING_PORT:
 428             if (al->cache.port != NULL) {
 429                 outint = al->cache.port->s.port();
 430                 doint = 1;
 431             }
 432             break;
 433
 434         case LFT_CLIENT_LOCAL_PORT:
 435             if (al->tcpClient != NULL) {
 436                 outint = al->tcpClient->local.port();
 437                 doint = 1;
 438             }
 439             break;
 440
 441         case LFT_SERVER_LOCAL_IP_OLD_27:
 442         case LFT_SERVER_LOCAL_IP:
 443             if (al->hier.tcpServer != NULL) {
 444                 out = al->hier.tcpServer->local.toStr(tmp,sizeof(tmp));
 445             }
 446             break;
 447
 448         case LFT_SERVER_LOCAL_PORT:
 449             if (al->hier.tcpServer != NULL) {
 450                 outint = al->hier.tcpServer->local.port();
 451                 doint = 1;
 452             }
 453
 454             break;
 455
 456         case LFT_SERVER_LOCAL_TOS:
 457             if (al->hier.tcpServer != NULL) {
 458                 snprintf(tmp, sizeof(tmp), "0x%x", (uint32_t)al->hier.tcpServer->tos);
 459                 out = tmp;
 460             }
 461             break;
 462
 463         case LFT_SERVER_LOCAL_NFMARK:
 464             if (al->hier.tcpServer != NULL) {
 465                 snprintf(tmp, sizeof(tmp), "0x%x", al->hier.tcpServer->nfmark);
 466                 out = tmp;
 467             }
 468             break;
 469
 470         case LFT_TIME_SECONDS_SINCE_EPOCH:
 471             // some platforms store time in 32-bit, some 64-bit...
 472             outoff = static_cast<int64_t>(current_time.tv_sec);
 473             dooff = 1;
 474             break;
 475
 476         case LFT_TIME_SUBSECOND:
 477             outint = current_time.tv_usec / fmt->divisor;
 478             doint = 1;
 479             break;
 480
 481         case LFT_TIME_LOCALTIME:
 482
 483         case LFT_TIME_GMT: {
 484             const char *spec;
 485
 486             struct tm *t;
 487             spec = fmt->data.string;
 488
 489             if (fmt->type == LFT_TIME_LOCALTIME) {
 490                 if (!spec)
 491                     spec = "%d/%b/%Y:%H:%M:%S %z";
 492                 t = localtime(&squid_curtime);
 493             } else {
 494                 if (!spec)
 495                     spec = "%d/%b/%Y:%H:%M:%S";
 496
 497                 t = gmtime(&squid_curtime);
 498             }
 499
 500             strftime(tmp, sizeof(tmp), spec, t);
 501
 502             out = tmp;
 503         }
 504
 505         break;
 506
 507         case LFT_TIME_START: {
 508             int precision = fmt->widthMax >=0 ? fmt->widthMax :3;
 509             snprintf(tmp, sizeof(tmp), "%0*" PRId64 ".%0*d", fmt->zero && (fmt->widthMin - precision - 1 >= 0) ? fmt->widthMin - precision - 1 : 0, static_cast<int64_t>(al->cache.start_time.tv_sec), precision, (int)(al->cache.start_time.tv_usec / fmt->divisor));
 510             out = tmp;
 511         }
 512         break;
 513
 514         case LFT_TIME_TO_HANDLE_REQUEST:
 515             outint = al->cache.msec;
 516             doint = 1;
 517             break;
 518
 519         case LFT_PEER_RESPONSE_TIME:
 520             if (al->hier.peer_response_time < 0) {
 521                 out = "-";
 522             } else {
 523                 outoff = al->hier.peer_response_time;
 524                 dooff = 1;
 525             }
 526             break;
 527
 528         case LFT_TOTAL_SERVER_SIDE_RESPONSE_TIME: {
 529             const int64_t total_response_time = al->hier.totalResponseTime();
 530             if (total_response_time < 0) {
 531                 out = "-";
 532             } else {
 533                 outoff = total_response_time;
 534                 dooff = 1;
 535             }
 536         }
 537         break;
 538
 539         case LFT_DNS_WAIT_TIME:
 540             if (al->request && al->request->dnsWait >= 0) {
 541                 outint = al->request->dnsWait;
 542                 doint = 1;
 543             }
 544             break;
 545
 546         case LFT_REQUEST_HEADER:
 547
 548             if (al->request)
 549                 sb = al->request->header.getByName(fmt->data.header.header);
 550
 551             out = sb.termedBuf();
 552
 553             quote = 1;
 554
 555             break;
 556
 557         case LFT_ADAPTED_REQUEST_HEADER:
 558
 559             if (al->adapted_request)
 560                 sb = al->adapted_request->header.getByName(fmt->data.header.header);
 561
 562             out = sb.termedBuf();
 563
 564             quote = 1;
 565
 566             break;
 567
 568         case LFT_REPLY_HEADER:
 569             if (al->reply)
 570                 sb = al->reply->header.getByName(fmt->data.header.header);
 571
 572             out = sb.termedBuf();
 573
 574             quote = 1;
 575
 576             break;
 577
 578 #if USE_ADAPTATION
 579         case LFT_ADAPTATION_SUM_XACT_TIMES:
 580             if (al->request) {
 581                 Adaptation::History::Pointer ah = al->request->adaptHistory();
 582                 if (ah != NULL)
 583                     ah->sumLogString(fmt->data.string, sb);
 584                 out = sb.termedBuf();
 585             }
 586             break;
 587
 588         case LFT_ADAPTATION_ALL_XACT_TIMES:
 589             if (al->request) {
 590                 Adaptation::History::Pointer ah = al->request->adaptHistory();
 591                 if (ah != NULL)
 592                     ah->allLogString(fmt->data.string, sb);
 593                 out = sb.termedBuf();
 594             }
 595             break;
 596
 597         case LFT_ADAPTATION_LAST_HEADER:
 598             if (al->request) {
 599                 const Adaptation::History::Pointer ah = al->request->adaptHistory();
 600                 if (ah != NULL) // XXX: add adapt::<all_h but use lastMeta here
 601                     sb = ah->allMeta.getByName(fmt->data.header.header);
 602             }
 603
 604             // XXX: here and elsewhere: move such code inside the if guard
 605             out = sb.termedBuf();
 606
 607             quote = 1;
 608
 609             break;
 610
 611         case LFT_ADAPTATION_LAST_HEADER_ELEM:
 612             if (al->request) {
 613                 const Adaptation::History::Pointer ah = al->request->adaptHistory();
 614                 if (ah != NULL) // XXX: add adapt::<all_h but use lastMeta here
 615                     sb = ah->allMeta.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
 616             }
 617
 618             out = sb.termedBuf();
 619
 620             quote = 1;
 621
 622             break;
 623
 624         case LFT_ADAPTATION_LAST_ALL_HEADERS:
 625             out = al->adapt.last_meta;
 626
 627             quote = 1;
 628
 629             break;
 630 #endif
 631
 632 #if ICAP_CLIENT
 633         case LFT_ICAP_ADDR:
 634             if (!out)
 635                 out = al->icap.hostAddr.toStr(tmp,1024);
 636             break;
 637
 638         case LFT_ICAP_SERV_NAME:
 639             out = al->icap.serviceName.termedBuf();
 640             break;
 641
 642         case LFT_ICAP_REQUEST_URI:
 643             out = al->icap.reqUri.termedBuf();
 644             break;
 645
 646         case LFT_ICAP_REQUEST_METHOD:
 647             out = Adaptation::Icap::ICAP::methodStr(al->icap.reqMethod);
 648             break;
 649
 650         case LFT_ICAP_BYTES_SENT:
 651             outoff = al->icap.bytesSent;
 652             dooff = 1;
 653             break;
 654
 655         case LFT_ICAP_BYTES_READ:
 656             outoff = al->icap.bytesRead;
 657             dooff = 1;
 658             break;
 659
 660         case LFT_ICAP_BODY_BYTES_READ:
 661             if (al->icap.bodyBytesRead >= 0) {
 662                 outoff = al->icap.bodyBytesRead;
 663                 dooff = 1;
 664             }
 665             // else if icap.bodyBytesRead < 0, we do not have any http data,
 666             // so just print a "-" (204 responses etc)
 667             break;
 668
 669         case LFT_ICAP_REQ_HEADER:
 670             if (NULL != al->icap.request) {
 671                 sb = al->icap.request->header.getByName(fmt->data.header.header);
 672                 out = sb.termedBuf();
 673                 quote = 1;
 674             }
 675             break;
 676
 677         case LFT_ICAP_REQ_HEADER_ELEM:
 678             if (al->icap.request)
 679                 sb = al->icap.request->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
 680
 681             out = sb.termedBuf();
 682
 683             quote = 1;
 684
 685             break;
 686
 687         case LFT_ICAP_REQ_ALL_HEADERS:
 688             if (al->icap.request) {
 689                 HttpHeaderPos pos = HttpHeaderInitPos;
 690                 while (const HttpHeaderEntry *e = al->icap.request->header.getEntry(&pos)) {
 691                     sb.append(e->name);
 692                     sb.append(": ");
 693                     sb.append(e->value);
 694                     sb.append("\r\n");
 695                 }
 696                 out = sb.termedBuf();
 697                 quote = 1;
 698             }
 699             break;
 700
 701         case LFT_ICAP_REP_HEADER:
 702             if (NULL != al->icap.reply) {
 703                 sb = al->icap.reply->header.getByName(fmt->data.header.header);
 704                 out = sb.termedBuf();
 705                 quote = 1;
 706             }
 707             break;
 708
 709         case LFT_ICAP_REP_HEADER_ELEM:
 710             if (NULL != al->icap.reply)
 711                 sb = al->icap.reply->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
 712
 713             out = sb.termedBuf();
 714
 715             quote = 1;
 716
 717             break;
 718
 719         case LFT_ICAP_REP_ALL_HEADERS:
 720             if (al->icap.reply) {
 721                 HttpHeaderPos pos = HttpHeaderInitPos;
 722                 while (const HttpHeaderEntry *e = al->icap.reply->header.getEntry(&pos)) {
 723                     sb.append(e->name);
 724                     sb.append(": ");
 725                     sb.append(e->value);
 726                     sb.append("\r\n");
 727                 }
 728                 out = sb.termedBuf();
 729                 quote = 1;
 730             }
 731             break;
 732
 733         case LFT_ICAP_TR_RESPONSE_TIME:
 734             outint = al->icap.trTime;
 735             doint = 1;
 736             break;
 737
 738         case LFT_ICAP_IO_TIME:
 739             outint = al->icap.ioTime;
 740             doint = 1;
 741             break;
 742
 743         case LFT_ICAP_STATUS_CODE:
 744             outint = al->icap.resStatus;
 745             doint  = 1;
 746             break;
 747
 748         case LFT_ICAP_OUTCOME:
 749             out = al->icap.outcome;
 750             break;
 751
 752         case LFT_ICAP_TOTAL_TIME:
 753             outint = al->icap.processingTime;
 754             doint = 1;
 755             break;
 756 #endif
 757         case LFT_REQUEST_HEADER_ELEM:
 758             if (al->request)
 759                 sb = al->request->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
 760
 761             out = sb.termedBuf();
 762
 763             quote = 1;
 764
 765             break;
 766
 767         case LFT_ADAPTED_REQUEST_HEADER_ELEM:
 768             if (al->adapted_request)
 769                 sb = al->adapted_request->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
 770
 771             out = sb.termedBuf();
 772
 773             quote = 1;
 774
 775             break;
 776
 777         case LFT_REPLY_HEADER_ELEM:
 778             if (al->reply)
 779                 sb = al->reply->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
 780
 781             out = sb.termedBuf();
 782
 783             quote = 1;
 784
 785             break;
 786
 787         case LFT_REQUEST_ALL_HEADERS:
 788             out = al->headers.request;
 789
 790             quote = 1;
 791
 792             break;
 793
 794         case LFT_ADAPTED_REQUEST_ALL_HEADERS:
 795             out = al->headers.adapted_request;
 796
 797             quote = 1;
 798
 799             break;
 800
 801         case LFT_REPLY_ALL_HEADERS:
 802             out = al->headers.reply;
 803
 804             quote = 1;
 805
 806             break;
 807
 808         case LFT_USER_NAME:
 809 #if USE_AUTH
 810             if (al->request && al->request->auth_user_request != NULL)
 811                 out = strOrNull(al->request->auth_user_request->username());
 812 #endif
 813             if (!out)
 814                 out = strOrNull(al->cache.extuser);
 815 #if USE_OPENSSL
 816             if (!out)
 817                 out = strOrNull(al->cache.ssluser);
 818 #endif
 819             if (!out)
 820                 out = strOrNull(al->cache.rfc931);
 821             break;
 822
 823         case LFT_USER_LOGIN:
 824 #if USE_AUTH
 825             if (al->request && al->request->auth_user_request != NULL)
 826                 out = strOrNull(al->request->auth_user_request->username());
 827 #endif
 828             break;
 829
 830         case LFT_USER_IDENT:
 831             out = strOrNull(al->cache.rfc931);
 832             break;
 833
 834         case LFT_USER_EXTERNAL:
 835             out = strOrNull(al->cache.extuser);
 836             break;
 837
 838             /* case LFT_USER_REALM: */
 839             /* case LFT_USER_SCHEME: */
 840
 841             // the fmt->type can not be LFT_HTTP_SENT_STATUS_CODE_OLD_30
 842             // but compiler complains if ommited
 843         case LFT_HTTP_SENT_STATUS_CODE_OLD_30:
 844         case LFT_HTTP_SENT_STATUS_CODE:
 845             outint = al->http.code;
 846
 847             doint = 1;
 848
 849             break;
 850
 851         case LFT_HTTP_RECEIVED_STATUS_CODE:
 852             if (al->hier.peer_reply_status == Http::scNone) {
 853                 out = "-";
 854             } else {
 855                 outint = al->hier.peer_reply_status;
 856                 doint = 1;
 857             }
 858             break;
 859             /* case LFT_HTTP_STATUS:
 860              *           out = statusline->text;
 861              *     quote = 1;
 862              *     break;
 863              */
 864         case LFT_HTTP_BODY_BYTES_READ:
 865             if (al->hier.bodyBytesRead >= 0) {
 866                 outoff = al->hier.bodyBytesRead;
 867                 dooff = 1;
 868             }
 869             // else if hier.bodyBytesRead < 0 we did not have any data exchange with
 870             // a peer server so just print a "-" (eg requests served from cache,
 871             // or internal error messages).
 872             break;
 873
 874         case LFT_SQUID_STATUS:
 875             if (al->http.timedout || al->http.aborted) {
 876                 snprintf(tmp, sizeof(tmp), "%s%s", LogTags_str[al->cache.code],
 877                          al->http.statusSfx());
 878                 out = tmp;
 879             } else {
 880                 out = LogTags_str[al->cache.code];
 881             }
 882
 883             break;
 884
 885         case LFT_SQUID_ERROR:
 886             if (al->request && al->request->errType != ERR_NONE)
 887                 out = errorPageName(al->request->errType);
 888             break;
 889
 890         case LFT_SQUID_ERROR_DETAIL:
 891 #if USE_OPENSSL
 892             if (al->request && al->request->errType == ERR_SECURE_CONNECT_FAIL) {
 893                 if (! (out = Ssl::GetErrorName(al->request->errDetail))) {
 894                     snprintf(tmp, sizeof(tmp), "SSL_ERR=%d", al->request->errDetail);
 895                     out = tmp;
 896                 }
 897             } else
 898 #endif
 899                 if (al->request && al->request->errDetail != ERR_DETAIL_NONE) {
 900                     if (al->request->errDetail > ERR_DETAIL_START  &&
 901                             al->request->errDetail < ERR_DETAIL_MAX)
 902                         out = errorDetailName(al->request->errDetail);
 903                     else {
 904                         if (al->request->errDetail >= ERR_DETAIL_EXCEPTION_START)
 905                             snprintf(tmp, sizeof(tmp), "%s=0x%X",
 906                                      errorDetailName(al->request->errDetail), (uint32_t) al->request->errDetail);
 907                         else
 908                             snprintf(tmp, sizeof(tmp), "%s=%d",
 909                                      errorDetailName(al->request->errDetail), al->request->errDetail);
 910                         out = tmp;
 911                     }
 912                 }
 913             break;
 914
 915         case LFT_SQUID_HIERARCHY:
 916             if (al->hier.ping.timedout)
 917                 mb.append("TIMEOUT_", 8);
 918
 919             out = hier_code_str[al->hier.code];
 920
 921             break;
 922
 923         case LFT_MIME_TYPE:
 924             out = al->http.content_type;
 925
 926             break;
 927
 928         case LFT_CLIENT_REQ_METHOD:
 929             if (al->request) {
 930                 const SBuf &s = al->request->method.image();
 931                 sb.append(s.rawContent(), s.length());
 932                 out = sb.termedBuf();
 933                 quote = 1;
 934             }
 935             break;
 936
 937         case LFT_CLIENT_REQ_URI:
 938             // original client URI
 939             if (al->request) {
 940                 out = urlCanonical(al->request);
 941                 quote = 1;
 942             }
 943             break;
 944
 945         case LFT_CLIENT_REQ_URLSCHEME:
 946             if (al->request) {
 947                 out = al->request->url.getScheme().c_str();
 948                 quote = 1;
 949             }
 950             break;
 951
 952         case LFT_CLIENT_REQ_URLDOMAIN:
 953             if (al->request) {
 954                 out = al->request->GetHost();
 955                 quote = 1;
 956             }
 957             break;
 958
 959         case LFT_CLIENT_REQ_URLPORT:
 960             if (al->request) {
 961                 outint = al->request->port;
 962                 doint = 1;
 963             }
 964             break;
 965
 966         case LFT_REQUEST_URLPATH_OLD_31:
 967         case LFT_CLIENT_REQ_URLPATH:
 968             if (al->request) {
 969                 out = al->request->urlpath.termedBuf();
 970                 quote = 1;
 971             }
 972             break;
 973
 974         case LFT_CLIENT_REQ_VERSION:
 975             if (al->request) {
 976                 snprintf(tmp, sizeof(tmp), "%d.%d", (int) al->request->http_ver.major, (int) al->request->http_ver.minor);
 977                 out = tmp;
 978             }
 979             break;
 980
 981         case LFT_REQUEST_METHOD:
 982             if (al->_private.method_str) // ICP, HTCP method code
 983                 out = al->_private.method_str;
 984             else {
 985                 const SBuf &s = al->http.method.image();
 986                 sb.append(s.rawContent(), s.length());
 987                 out = sb.termedBuf();
 988                 quote = 1;
 989             }
 990             break;
 991
 992         case LFT_REQUEST_URI:
 993             out = al->url;
 994             break;
 995
 996         case LFT_REQUEST_VERSION_OLD_2X:
 997         case LFT_REQUEST_VERSION:
 998             snprintf(tmp, sizeof(tmp), "%d.%d", (int) al->http.version.major, (int) al->http.version.minor);
 999             out = tmp;
1000             break;
1001
1002         case LFT_SERVER_REQ_METHOD:
1003             if (al->adapted_request) {
1004                 const SBuf &s = al->adapted_request->method.image();
1005                 sb.append(s.rawContent(), s.length());
1006                 out = sb.termedBuf();
1007                 quote = 1;
1008             }
1009             break;
1010
1011         case LFT_SERVER_REQ_URI:
1012             // adapted request URI sent to server/peer
1013             if (al->adapted_request) {
1014                 out = urlCanonical(al->adapted_request);
1015                 quote = 1;
1016             }
1017             break;
1018
1019         case LFT_SERVER_REQ_URLSCHEME:
1020             if (al->adapted_request) {
1021                 out = al->adapted_request->url.getScheme().c_str();
1022                 quote = 1;
1023             }
1024             break;
1025
1026         case LFT_SERVER_REQ_URLDOMAIN:
1027             if (al->adapted_request) {
1028                 out = al->adapted_request->GetHost();
1029                 quote = 1;
1030             }
1031             break;
1032
1033         case LFT_SERVER_REQ_URLPORT:
1034             if (al->adapted_request) {
1035                 outint = al->adapted_request->port;
1036                 doint = 1;
1037             }
1038             break;
1039
1040         case LFT_SERVER_REQ_URLPATH:
1041             if (al->adapted_request) {
1042                 out = al->adapted_request->urlpath.termedBuf();
1043                 quote = 1;
1044             }
1045             break;
1046
1047         case LFT_SERVER_REQ_VERSION:
1048             if (al->adapted_request) {
1049                 snprintf(tmp, sizeof(tmp), "%d.%d",
1050                          (int) al->adapted_request->http_ver.major,
1051                          (int) al->adapted_request->http_ver.minor);
1052                 out = tmp;
1053             }
1054             break;
1055
1056         case LFT_CLIENT_REQUEST_SIZE_TOTAL:
1057             outoff = al->http.clientRequestSz.messageTotal();
1058             dooff = 1;
1059             break;
1060
1061         case LFT_CLIENT_REQUEST_SIZE_HEADERS:
1062             outoff = al->http.clientRequestSz.header;
1063             dooff =1;
1064             break;
1065
1066             /*case LFT_REQUEST_SIZE_BODY: */
1067             /*case LFT_REQUEST_SIZE_BODY_NO_TE: */
1068
1069         case LFT_ADAPTED_REPLY_SIZE_TOTAL:
1070             outoff = al->http.clientReplySz.messageTotal();
1071             dooff = 1;
1072             break;
1073
1074         case LFT_REPLY_HIGHOFFSET:
1075             outoff = al->cache.highOffset;
1076
1077             dooff = 1;
1078
1079             break;
1080
1081         case LFT_REPLY_OBJECTSIZE:
1082             outoff = al->cache.objectSize;
1083
1084             dooff = 1;
1085
1086             break;
1087
1088         case LFT_ADAPTED_REPLY_SIZE_HEADERS:
1089             outint = al->http.clientReplySz.header;
1090             doint = 1;
1091             break;
1092
1093             /*case LFT_REPLY_SIZE_BODY: */
1094             /*case LFT_REPLY_SIZE_BODY_NO_TE: */
1095
1096         case LFT_CLIENT_IO_SIZE_TOTAL:
1097             outint = al->http.clientRequestSz.messageTotal() + al->http.clientReplySz.messageTotal();
1098             doint = 1;
1099             break;
1100             /*case LFT_SERVER_IO_SIZE_TOTAL: */
1101
1102         case LFT_TAG:
1103             if (al->request)
1104                 out = al->request->tag.termedBuf();
1105
1106             quote = 1;
1107
1108             break;
1109
1110         case LFT_EXT_LOG:
1111             if (al->request)
1112                 out = al->request->extacl_log.termedBuf();
1113
1114             quote = 1;
1115
1116             break;
1117
1118         case LFT_SEQUENCE_NUMBER:
1119             outoff = logSequenceNumber;
1120             dooff = 1;
1121             break;
1122
1123 #if USE_OPENSSL
1124         case LFT_SSL_BUMP_MODE: {
1125             const Ssl::BumpMode mode = static_cast<Ssl::BumpMode>(al->ssl.bumpMode);
1126             // for Ssl::bumpEnd, Ssl::bumpMode() returns NULL and we log '-'
1127             out = Ssl::bumpMode(mode);
1128             break;
1129         }
1130
1131         case LFT_SSL_USER_CERT_SUBJECT:
1132             if (X509 *cert = al->cache.sslClientCert.get()) {
1133                 if (X509_NAME *subject = X509_get_subject_name(cert)) {
1134                     X509_NAME_oneline(subject, tmp, sizeof(tmp));
1135                     out = tmp;
1136                 }
1137             }
1138             break;
1139
1140         case LFT_SSL_USER_CERT_ISSUER:
1141             if (X509 *cert = al->cache.sslClientCert.get()) {
1142                 if (X509_NAME *issuer = X509_get_issuer_name(cert)) {
1143                     X509_NAME_oneline(issuer, tmp, sizeof(tmp));
1144                     out = tmp;
1145                 }
1146             }
1147             break;
1148         case LFT_SSL_CLIENT_SNI:
1149             if (al->request && al->request->clientConnectionManager.valid()) {
1150                 if (Ssl::ServerBump * srvBump = al->request->clientConnectionManager->serverBump()) {
1151                     if (!srvBump->clientSni.isEmpty())
1152                         out = srvBump->clientSni.c_str();
1153                 }
1154             }
1155             break;
1156
1157         case LFT_SSL_SERVER_CERT_ISSUER:
1158         case LFT_SSL_SERVER_CERT_SUBJECT:
1159             // Not implemented
1160             break;
1161 #endif
1162
1163         case LFT_REQUEST_URLGROUP_OLD_2X:
1164             assert(LFT_REQUEST_URLGROUP_OLD_2X == 0); // should never happen.
1165
1166         case LFT_NOTE:
1167             tmp[0] = fmt->data.header.separator;
1168             tmp[1] = '\0';
1169             if (fmt->data.header.header && *fmt->data.header.header) {
1170                 const char *separator = tmp;
1171 #if USE_ADAPTATION
1172                 Adaptation::History::Pointer ah = al->request ? al->request->adaptHistory() : Adaptation::History::Pointer();
1173                 if (ah != NULL && ah->metaHeaders != NULL) {
1174                     if (const char *meta = ah->metaHeaders->find(fmt->data.header.header, separator))
1175                         sb.append(meta);
1176                 }
1177 #endif
1178                 if (al->notes != NULL) {
1179                     if (const char *note = al->notes->find(fmt->data.header.header, separator)) {
1180                         if (sb.size())
1181                             sb.append(separator);
1182                         sb.append(note);
1183                     }
1184                 }
1185                 out = sb.termedBuf();
1186                 quote = 1;
1187             } else {
1188                 // if no argument given use default "\r\n" as notes separator
1189                 const char *separator = fmt->data.string ? tmp : "\r\n";
1190 #if USE_ADAPTATION
1191                 Adaptation::History::Pointer ah = al->request ? al->request->adaptHistory() : Adaptation::History::Pointer();
1192                 if (ah != NULL && ah->metaHeaders != NULL && !ah->metaHeaders->empty())
1193                     sb.append(ah->metaHeaders->toString(separator));
1194 #endif
1195                 if (al->notes != NULL && !al->notes->empty())
1196                     sb.append(al->notes->toString(separator));
1197
1198                 out = sb.termedBuf();
1199                 quote = 1;
1200             }
1201             break;
1202
1203         case LFT_CREDENTIALS:
1204 #if USE_AUTH
1205             if (al->request && al->request->auth_user_request != NULL)
1206                 out = strOrNull(al->request->auth_user_request->credentialsStr());
1207 #endif
1208
1209             break;
1210
1211         case LFT_PERCENT:
1212             out = "%";
1213             break;
1214
1215             // XXX: external_acl_type format tokens which are not output by logformat.
1216             // They are listed here because the switch requires
1217             // every ByteCode_t to be explicitly enumerated.
1218             // But do not output due to lack of access to the values.
1219         case LFT_EXT_ACL_USER_CERT_RAW:
1220         case LFT_EXT_ACL_USER_CERTCHAIN_RAW:
1221         case LFT_EXT_ACL_USER_CERT:
1222         case LFT_EXT_ACL_USER_CA_CERT:
1223         case LFT_EXT_ACL_CLIENT_EUI48:
1224         case LFT_EXT_ACL_CLIENT_EUI64:
1225         case LFT_EXT_ACL_NAME:
1226         case LFT_EXT_ACL_DATA:
1227             break;
1228         }
1229
1230         if (dooff) {
1231             snprintf(tmp, sizeof(tmp), "%0*" PRId64, fmt->zero && fmt->widthMin >= 0 ? fmt->widthMin : 0, outoff);
1232             out = tmp;
1233
1234         } else if (doint) {
1235             snprintf(tmp, sizeof(tmp), "%0*ld", fmt->zero && fmt->widthMin >= 0 ? fmt->widthMin : 0, outint);
1236             out = tmp;
1237         }
1238
1239         if (out && *out) {
1240             if (quote || fmt->quote != LOG_QUOTE_NONE) {
1241                 char *newout = NULL;
1242                 int newfree = 0;
1243
1244                 switch (fmt->quote) {
1245
1246                 case LOG_QUOTE_NONE:
1247                     newout = rfc1738_escape_unescaped(out);
1248                     break;
1249
1250                 case LOG_QUOTE_QUOTES: {
1251                     size_t out_len = static_cast<size_t>(strlen(out)) * 2 + 1;
1252                     if (out_len >= sizeof(tmp)) {
1253                         newout = (char *)xmalloc(out_len);
1254                         newfree = 1;
1255                     } else
1256                         newout = tmp;
1257                     log_quoted_string(out, newout);
1258                 }
1259                 break;
1260
1261                 case LOG_QUOTE_MIMEBLOB:
1262                     newout = QuoteMimeBlob(out);
1263                     newfree = 1;
1264                     break;
1265
1266                 case LOG_QUOTE_URL:
1267                     newout = rfc1738_escape(out);
1268                     break;
1269
1270                 case LOG_QUOTE_RAW:
1271                     break;
1272                 }
1273
1274                 if (newout) {
1275                     if (dofree)
1276                         safe_free(out);
1277
1278                     out = newout;
1279
1280                     dofree = newfree;
1281                 }
1282             }
1283
1284             // enforce width limits if configured
1285             const bool haveMaxWidth = fmt->widthMax >=0 && !doint && !dooff && !fmt->divisor;
1286             if (haveMaxWidth || fmt->widthMin) {
1287                 const int minWidth = fmt->widthMin >= 0 ?
1288                                      fmt->widthMin :0;
1289                 const int maxWidth = haveMaxWidth ?
1290                                      fmt->widthMax : strlen(out);
1291
1292                 if (fmt->left)
1293                     mb.Printf("%-*.*s", minWidth, maxWidth, out);
1294                 else
1295                     mb.Printf("%*.*s", minWidth, maxWidth, out);
1296             } else
1297                 mb.append(out, strlen(out));
1298         } else {
1299             mb.append("-", 1);
1300         }
1301
1302         if (fmt->space)
1303             mb.append(" ", 1);
1304
1305         sb.clean();
1306
1307         if (dofree)
1308             safe_free(out);
1309     }
1310 }