src/format/Format.cc

   1 /*
   2  * Copyright (C) 1996-2015 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         struct timeval outtv = {0, 0};
 327         int doMsec = 0;
 328         int doSec = 0;
 329
 330         switch (fmt->type) {
 331
 332         case LFT_NONE:
 333             out = "";
 334             break;
 335
 336         case LFT_STRING:
 337             out = fmt->data.string;
 338             break;
 339
 340         case LFT_CLIENT_IP_ADDRESS:
 341             al->getLogClientIp(tmp, sizeof(tmp));
 342             out = tmp;
 343             break;
 344
 345         case LFT_CLIENT_FQDN:
 346             if (al->cache.caddr.isAnyAddr()) // e.g., ICAP OPTIONS lack client
 347                 out = "-";
 348             else
 349                 out = fqdncache_gethostbyaddr(al->cache.caddr, FQDN_LOOKUP_IF_MISS);
 350             if (!out) {
 351                 out = al->cache.caddr.toStr(tmp,1024);
 352             }
 353
 354             break;
 355
 356         case LFT_CLIENT_PORT:
 357             if (al->request) {
 358                 outint = al->request->client_addr.port();
 359                 doint = 1;
 360             }
 361             break;
 362
 363         case LFT_CLIENT_EUI:
 364 #if USE_SQUID_EUI
 365             // TODO make the ACL checklist have a direct link to any TCP details.
 366             if (al->request && al->request->clientConnectionManager.valid() && al->request->clientConnectionManager->clientConnection != NULL) {
 367                 if (al->request->clientConnectionManager->clientConnection->remote.isIPv4())
 368                     al->request->clientConnectionManager->clientConnection->remoteEui48.encode(tmp, 1024);
 369                 else
 370                     al->request->clientConnectionManager->clientConnection->remoteEui64.encode(tmp, 1024);
 371                 out = tmp;
 372             }
 373 #else
 374             out = "-";
 375 #endif
 376             break;
 377
 378         case LFT_SERVER_IP_ADDRESS:
 379             if (al->hier.tcpServer != NULL) {
 380                 out = al->hier.tcpServer->remote.toStr(tmp,sizeof(tmp));
 381             }
 382             break;
 383
 384         case LFT_SERVER_FQDN_OR_PEER_NAME:
 385             out = al->hier.host;
 386             break;
 387
 388         case LFT_SERVER_PORT:
 389             if (al->hier.tcpServer != NULL) {
 390                 outint = al->hier.tcpServer->remote.port();
 391                 doint = 1;
 392             }
 393             break;
 394
 395         case LFT_LOCAL_LISTENING_IP: {
 396             // avoid logging a dash if we have reliable info
 397             const bool interceptedAtKnownPort = al->request ?
 398                                                 (al->request->flags.interceptTproxy ||
 399                                                  al->request->flags.intercepted) && al->cache.port != NULL :
 400                                                 false;
 401             if (interceptedAtKnownPort) {
 402                 const bool portAddressConfigured = !al->cache.port->s.isAnyAddr();
 403                 if (portAddressConfigured)
 404                     out = al->cache.port->s.toStr(tmp, sizeof(tmp));
 405             } else if (al->tcpClient != NULL)
 406                 out = al->tcpClient->local.toStr(tmp, sizeof(tmp));
 407         }
 408         break;
 409
 410         case LFT_CLIENT_LOCAL_IP:
 411             if (al->tcpClient != NULL) {
 412                 out = al->tcpClient->local.toStr(tmp,sizeof(tmp));
 413             }
 414             break;
 415
 416         case LFT_CLIENT_LOCAL_TOS:
 417             if (al->tcpClient != NULL) {
 418                 snprintf(tmp, sizeof(tmp), "0x%x", (uint32_t)al->tcpClient->tos);
 419                 out = tmp;
 420             }
 421             break;
 422
 423         case LFT_CLIENT_LOCAL_NFMARK:
 424             if (al->tcpClient != NULL) {
 425                 snprintf(tmp, sizeof(tmp), "0x%x", al->tcpClient->nfmark);
 426                 out = tmp;
 427             }
 428             break;
 429
 430         case LFT_LOCAL_LISTENING_PORT:
 431             if (al->cache.port != NULL) {
 432                 outint = al->cache.port->s.port();
 433                 doint = 1;
 434             }
 435             break;
 436
 437         case LFT_CLIENT_LOCAL_PORT:
 438             if (al->tcpClient != NULL) {
 439                 outint = al->tcpClient->local.port();
 440                 doint = 1;
 441             }
 442             break;
 443
 444         case LFT_SERVER_LOCAL_IP_OLD_27:
 445         case LFT_SERVER_LOCAL_IP:
 446             if (al->hier.tcpServer != NULL) {
 447                 out = al->hier.tcpServer->local.toStr(tmp,sizeof(tmp));
 448             }
 449             break;
 450
 451         case LFT_SERVER_LOCAL_PORT:
 452             if (al->hier.tcpServer != NULL) {
 453                 outint = al->hier.tcpServer->local.port();
 454                 doint = 1;
 455             }
 456
 457             break;
 458
 459         case LFT_SERVER_LOCAL_TOS:
 460             if (al->hier.tcpServer != NULL) {
 461                 snprintf(tmp, sizeof(tmp), "0x%x", (uint32_t)al->hier.tcpServer->tos);
 462                 out = tmp;
 463             }
 464             break;
 465
 466         case LFT_SERVER_LOCAL_NFMARK:
 467             if (al->hier.tcpServer != NULL) {
 468                 snprintf(tmp, sizeof(tmp), "0x%x", al->hier.tcpServer->nfmark);
 469                 out = tmp;
 470             }
 471             break;
 472
 473         case LFT_TIME_SECONDS_SINCE_EPOCH:
 474             // some platforms store time in 32-bit, some 64-bit...
 475             outoff = static_cast<int64_t>(current_time.tv_sec);
 476             dooff = 1;
 477             break;
 478
 479         case LFT_TIME_SUBSECOND:
 480             outint = current_time.tv_usec / fmt->divisor;
 481             doint = 1;
 482             break;
 483
 484         case LFT_TIME_LOCALTIME:
 485
 486         case LFT_TIME_GMT: {
 487             const char *spec;
 488
 489             struct tm *t;
 490             spec = fmt->data.string;
 491
 492             if (fmt->type == LFT_TIME_LOCALTIME) {
 493                 if (!spec)
 494                     spec = "%d/%b/%Y:%H:%M:%S %z";
 495                 t = localtime(&squid_curtime);
 496             } else {
 497                 if (!spec)
 498                     spec = "%d/%b/%Y:%H:%M:%S";
 499
 500                 t = gmtime(&squid_curtime);
 501             }
 502
 503             strftime(tmp, sizeof(tmp), spec, t);
 504
 505             out = tmp;
 506         }
 507
 508         break;
 509
 510         case LFT_TIME_START:
 511             outtv = al->cache.start_time;
 512             doSec = 1;
 513             break;
 514
 515         case LFT_TIME_TO_HANDLE_REQUEST:
 516             outtv = al->cache.trTime;
 517             doMsec = 1;
 518             break;
 519
 520         case LFT_PEER_RESPONSE_TIME:
 521             if (al->hier.peer_response_time.tv_sec ==  -1) {
 522                 out = "-";
 523             } else {
 524                 outtv = al->hier.peer_response_time;
 525                 doMsec = 1;
 526             }
 527             break;
 528
 529         case LFT_TOTAL_SERVER_SIDE_RESPONSE_TIME: {
 530             timeval total_response_time;
 531             al->hier.totalResponseTime(total_response_time);
 532             if (total_response_time.tv_sec == -1) {
 533                 out = "-";
 534             } else {
 535                 outtv = total_response_time;
 536                 doMsec = 1;
 537             }
 538         }
 539         break;
 540
 541         case LFT_DNS_WAIT_TIME:
 542             if (al->request && al->request->dnsWait >= 0) {
 543                 // TODO: microsecond precision for dns wait time.
 544                 // Convert miliseconds to timeval struct:
 545                 outtv.tv_sec = al->request->dnsWait / 1000;
 546                 outtv.tv_usec = (al->request->dnsWait % 1000) * 1000;
 547                 doMsec = 1;
 548             }
 549             break;
 550
 551         case LFT_REQUEST_HEADER:
 552
 553             if (al->request)
 554                 sb = al->request->header.getByName(fmt->data.header.header);
 555
 556             out = sb.termedBuf();
 557
 558             quote = 1;
 559
 560             break;
 561
 562         case LFT_ADAPTED_REQUEST_HEADER:
 563
 564             if (al->adapted_request)
 565                 sb = al->adapted_request->header.getByName(fmt->data.header.header);
 566
 567             out = sb.termedBuf();
 568
 569             quote = 1;
 570
 571             break;
 572
 573         case LFT_REPLY_HEADER:
 574             if (al->reply)
 575                 sb = al->reply->header.getByName(fmt->data.header.header);
 576
 577             out = sb.termedBuf();
 578
 579             quote = 1;
 580
 581             break;
 582
 583 #if USE_ADAPTATION
 584         case LFT_ADAPTATION_SUM_XACT_TIMES:
 585             if (al->request) {
 586                 Adaptation::History::Pointer ah = al->request->adaptHistory();
 587                 if (ah != NULL)
 588                     ah->sumLogString(fmt->data.string, sb);
 589                 out = sb.termedBuf();
 590             }
 591             break;
 592
 593         case LFT_ADAPTATION_ALL_XACT_TIMES:
 594             if (al->request) {
 595                 Adaptation::History::Pointer ah = al->request->adaptHistory();
 596                 if (ah != NULL)
 597                     ah->allLogString(fmt->data.string, sb);
 598                 out = sb.termedBuf();
 599             }
 600             break;
 601
 602         case LFT_ADAPTATION_LAST_HEADER:
 603             if (al->request) {
 604                 const Adaptation::History::Pointer ah = al->request->adaptHistory();
 605                 if (ah != NULL) // XXX: add adapt::<all_h but use lastMeta here
 606                     sb = ah->allMeta.getByName(fmt->data.header.header);
 607             }
 608
 609             // XXX: here and elsewhere: move such code inside the if guard
 610             out = sb.termedBuf();
 611
 612             quote = 1;
 613
 614             break;
 615
 616         case LFT_ADAPTATION_LAST_HEADER_ELEM:
 617             if (al->request) {
 618                 const Adaptation::History::Pointer ah = al->request->adaptHistory();
 619                 if (ah != NULL) // XXX: add adapt::<all_h but use lastMeta here
 620                     sb = ah->allMeta.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
 621             }
 622
 623             out = sb.termedBuf();
 624
 625             quote = 1;
 626
 627             break;
 628
 629         case LFT_ADAPTATION_LAST_ALL_HEADERS:
 630             out = al->adapt.last_meta;
 631
 632             quote = 1;
 633
 634             break;
 635 #endif
 636
 637 #if ICAP_CLIENT
 638         case LFT_ICAP_ADDR:
 639             if (!out)
 640                 out = al->icap.hostAddr.toStr(tmp,1024);
 641             break;
 642
 643         case LFT_ICAP_SERV_NAME:
 644             out = al->icap.serviceName.termedBuf();
 645             break;
 646
 647         case LFT_ICAP_REQUEST_URI:
 648             out = al->icap.reqUri.termedBuf();
 649             break;
 650
 651         case LFT_ICAP_REQUEST_METHOD:
 652             out = Adaptation::Icap::ICAP::methodStr(al->icap.reqMethod);
 653             break;
 654
 655         case LFT_ICAP_BYTES_SENT:
 656             outoff = al->icap.bytesSent;
 657             dooff = 1;
 658             break;
 659
 660         case LFT_ICAP_BYTES_READ:
 661             outoff = al->icap.bytesRead;
 662             dooff = 1;
 663             break;
 664
 665         case LFT_ICAP_BODY_BYTES_READ:
 666             if (al->icap.bodyBytesRead >= 0) {
 667                 outoff = al->icap.bodyBytesRead;
 668                 dooff = 1;
 669             }
 670             // else if icap.bodyBytesRead < 0, we do not have any http data,
 671             // so just print a "-" (204 responses etc)
 672             break;
 673
 674         case LFT_ICAP_REQ_HEADER:
 675             if (NULL != al->icap.request) {
 676                 sb = al->icap.request->header.getByName(fmt->data.header.header);
 677                 out = sb.termedBuf();
 678                 quote = 1;
 679             }
 680             break;
 681
 682         case LFT_ICAP_REQ_HEADER_ELEM:
 683             if (al->icap.request)
 684                 sb = al->icap.request->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
 685
 686             out = sb.termedBuf();
 687
 688             quote = 1;
 689
 690             break;
 691
 692         case LFT_ICAP_REQ_ALL_HEADERS:
 693             if (al->icap.request) {
 694                 HttpHeaderPos pos = HttpHeaderInitPos;
 695                 while (const HttpHeaderEntry *e = al->icap.request->header.getEntry(&pos)) {
 696                     sb.append(e->name);
 697                     sb.append(": ");
 698                     sb.append(e->value);
 699                     sb.append("\r\n");
 700                 }
 701                 out = sb.termedBuf();
 702                 quote = 1;
 703             }
 704             break;
 705
 706         case LFT_ICAP_REP_HEADER:
 707             if (NULL != al->icap.reply) {
 708                 sb = al->icap.reply->header.getByName(fmt->data.header.header);
 709                 out = sb.termedBuf();
 710                 quote = 1;
 711             }
 712             break;
 713
 714         case LFT_ICAP_REP_HEADER_ELEM:
 715             if (NULL != al->icap.reply)
 716                 sb = al->icap.reply->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
 717
 718             out = sb.termedBuf();
 719
 720             quote = 1;
 721
 722             break;
 723
 724         case LFT_ICAP_REP_ALL_HEADERS:
 725             if (al->icap.reply) {
 726                 HttpHeaderPos pos = HttpHeaderInitPos;
 727                 while (const HttpHeaderEntry *e = al->icap.reply->header.getEntry(&pos)) {
 728                     sb.append(e->name);
 729                     sb.append(": ");
 730                     sb.append(e->value);
 731                     sb.append("\r\n");
 732                 }
 733                 out = sb.termedBuf();
 734                 quote = 1;
 735             }
 736             break;
 737
 738         case LFT_ICAP_TR_RESPONSE_TIME:
 739             outtv = al->icap.trTime;
 740             doMsec = 1;
 741             break;
 742
 743         case LFT_ICAP_IO_TIME:
 744             outtv = al->icap.ioTime;
 745             doMsec = 1;
 746             break;
 747
 748         case LFT_ICAP_STATUS_CODE:
 749             outint = al->icap.resStatus;
 750             doint  = 1;
 751             break;
 752
 753         case LFT_ICAP_OUTCOME:
 754             out = al->icap.outcome;
 755             break;
 756
 757         case LFT_ICAP_TOTAL_TIME:
 758             outtv = al->icap.processingTime;
 759             doMsec = 1;
 760             break;
 761 #endif
 762         case LFT_REQUEST_HEADER_ELEM:
 763             if (al->request)
 764                 sb = al->request->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
 765
 766             out = sb.termedBuf();
 767
 768             quote = 1;
 769
 770             break;
 771
 772         case LFT_ADAPTED_REQUEST_HEADER_ELEM:
 773             if (al->adapted_request)
 774                 sb = al->adapted_request->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
 775
 776             out = sb.termedBuf();
 777
 778             quote = 1;
 779
 780             break;
 781
 782         case LFT_REPLY_HEADER_ELEM:
 783             if (al->reply)
 784                 sb = al->reply->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
 785
 786             out = sb.termedBuf();
 787
 788             quote = 1;
 789
 790             break;
 791
 792         case LFT_REQUEST_ALL_HEADERS:
 793             out = al->headers.request;
 794
 795             quote = 1;
 796
 797             break;
 798
 799         case LFT_ADAPTED_REQUEST_ALL_HEADERS:
 800             out = al->headers.adapted_request;
 801
 802             quote = 1;
 803
 804             break;
 805
 806         case LFT_REPLY_ALL_HEADERS:
 807             out = al->headers.reply;
 808
 809             quote = 1;
 810
 811             break;
 812
 813         case LFT_USER_NAME:
 814 #if USE_AUTH
 815             if (al->request && al->request->auth_user_request != NULL)
 816                 out = strOrNull(al->request->auth_user_request->username());
 817 #endif
 818             if (!out)
 819                 out = strOrNull(al->cache.extuser);
 820 #if USE_OPENSSL
 821             if (!out)
 822                 out = strOrNull(al->cache.ssluser);
 823 #endif
 824             if (!out)
 825                 out = strOrNull(al->cache.rfc931);
 826             break;
 827
 828         case LFT_USER_LOGIN:
 829 #if USE_AUTH
 830             if (al->request && al->request->auth_user_request != NULL)
 831                 out = strOrNull(al->request->auth_user_request->username());
 832 #endif
 833             break;
 834
 835         case LFT_USER_IDENT:
 836             out = strOrNull(al->cache.rfc931);
 837             break;
 838
 839         case LFT_USER_EXTERNAL:
 840             out = strOrNull(al->cache.extuser);
 841             break;
 842
 843         /* case LFT_USER_REALM: */
 844         /* case LFT_USER_SCHEME: */
 845
 846         // the fmt->type can not be LFT_HTTP_SENT_STATUS_CODE_OLD_30
 847         // but compiler complains if ommited
 848         case LFT_HTTP_SENT_STATUS_CODE_OLD_30:
 849         case LFT_HTTP_SENT_STATUS_CODE:
 850             outint = al->http.code;
 851
 852             doint = 1;
 853
 854             break;
 855
 856         case LFT_HTTP_RECEIVED_STATUS_CODE:
 857             if (al->hier.peer_reply_status == Http::scNone) {
 858                 out = "-";
 859             } else {
 860                 outint = al->hier.peer_reply_status;
 861                 doint = 1;
 862             }
 863             break;
 864         /* case LFT_HTTP_STATUS:
 865          *           out = statusline->text;
 866          *     quote = 1;
 867          *     break;
 868          */
 869         case LFT_HTTP_BODY_BYTES_READ:
 870             if (al->hier.bodyBytesRead >= 0) {
 871                 outoff = al->hier.bodyBytesRead;
 872                 dooff = 1;
 873             }
 874             // else if hier.bodyBytesRead < 0 we did not have any data exchange with
 875             // a peer server so just print a "-" (eg requests served from cache,
 876             // or internal error messages).
 877             break;
 878
 879         case LFT_SQUID_STATUS:
 880             out = al->cache.code.c_str();
 881             break;
 882
 883         case LFT_SQUID_ERROR:
 884             if (al->request && al->request->errType != ERR_NONE)
 885                 out = errorPageName(al->request->errType);
 886             break;
 887
 888         case LFT_SQUID_ERROR_DETAIL:
 889 #if USE_OPENSSL
 890             if (al->request && al->request->errType == ERR_SECURE_CONNECT_FAIL) {
 891                 if (! (out = Ssl::GetErrorName(al->request->errDetail))) {
 892                     snprintf(tmp, sizeof(tmp), "SSL_ERR=%d", al->request->errDetail);
 893                     out = tmp;
 894                 }
 895             } else
 896 #endif
 897                 if (al->request && al->request->errDetail != ERR_DETAIL_NONE) {
 898                     if (al->request->errDetail > ERR_DETAIL_START  &&
 899                             al->request->errDetail < ERR_DETAIL_MAX)
 900                         out = errorDetailName(al->request->errDetail);
 901                     else {
 902                         if (al->request->errDetail >= ERR_DETAIL_EXCEPTION_START)
 903                             snprintf(tmp, sizeof(tmp), "%s=0x%X",
 904                                      errorDetailName(al->request->errDetail), (uint32_t) al->request->errDetail);
 905                         else
 906                             snprintf(tmp, sizeof(tmp), "%s=%d",
 907                                      errorDetailName(al->request->errDetail), al->request->errDetail);
 908                         out = tmp;
 909                     }
 910                 }
 911             break;
 912
 913         case LFT_SQUID_HIERARCHY:
 914             if (al->hier.ping.timedout)
 915                 mb.append("TIMEOUT_", 8);
 916
 917             out = hier_code_str[al->hier.code];
 918
 919             break;
 920
 921         case LFT_MIME_TYPE:
 922             out = al->http.content_type;
 923
 924             break;
 925
 926         case LFT_CLIENT_REQ_METHOD:
 927             if (al->request) {
 928                 const SBuf &s = al->request->method.image();
 929                 sb.append(s.rawContent(), s.length());
 930                 out = sb.termedBuf();
 931                 quote = 1;
 932             }
 933             break;
 934
 935         case LFT_CLIENT_REQ_URI:
 936             // original client URI
 937             if (al->request) {
 938                 const SBuf &s = al->request->effectiveRequestUri();
 939                 sb.append(s.rawContent(), s.length());
 940                 out = sb.termedBuf();
 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->url.host();
 955                 quote = 1;
 956             }
 957             break;
 958
 959         case LFT_CLIENT_REQ_URLPORT:
 960             if (al->request) {
 961                 outint = al->request->url.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                 SBuf s = al->request->url.path();
 970                 out = s.c_str();
 971                 quote = 1;
 972             }
 973             break;
 974
 975         case LFT_CLIENT_REQ_VERSION:
 976             if (al->request) {
 977                 snprintf(tmp, sizeof(tmp), "%d.%d", (int) al->request->http_ver.major, (int) al->request->http_ver.minor);
 978                 out = tmp;
 979             }
 980             break;
 981
 982         case LFT_REQUEST_METHOD:
 983             if (al->_private.method_str) // ICP, HTCP method code
 984                 out = al->_private.method_str;
 985             else {
 986                 const SBuf &s = al->http.method.image();
 987                 sb.append(s.rawContent(), s.length());
 988                 out = sb.termedBuf();
 989                 quote = 1;
 990             }
 991             break;
 992
 993         case LFT_REQUEST_URI:
 994             out = al->url;
 995             break;
 996
 997         case LFT_REQUEST_VERSION_OLD_2X:
 998         case LFT_REQUEST_VERSION:
 999             snprintf(tmp, sizeof(tmp), "%d.%d", (int) al->http.version.major, (int) al->http.version.minor);
1000             out = tmp;
1001             break;
1002
1003         case LFT_SERVER_REQ_METHOD:
1004             if (al->adapted_request) {
1005                 const SBuf &s = al->adapted_request->method.image();
1006                 sb.append(s.rawContent(), s.length());
1007                 out = sb.termedBuf();
1008                 quote = 1;
1009             }
1010             break;
1011
1012         case LFT_SERVER_REQ_URI:
1013             // adapted request URI sent to server/peer
1014             if (al->adapted_request) {
1015                 const SBuf &s = al->adapted_request->effectiveRequestUri();
1016                 sb.append(s.rawContent(), s.length());
1017                 out = sb.termedBuf();
1018                 quote = 1;
1019             }
1020             break;
1021
1022         case LFT_SERVER_REQ_URLSCHEME:
1023             if (al->adapted_request) {
1024                 out = al->adapted_request->url.getScheme().c_str();
1025                 quote = 1;
1026             }
1027             break;
1028
1029         case LFT_SERVER_REQ_URLDOMAIN:
1030             if (al->adapted_request) {
1031                 out = al->adapted_request->url.host();
1032                 quote = 1;
1033             }
1034             break;
1035
1036         case LFT_SERVER_REQ_URLPORT:
1037             if (al->adapted_request) {
1038                 outint = al->adapted_request->url.port();
1039                 doint = 1;
1040             }
1041             break;
1042
1043         case LFT_SERVER_REQ_URLPATH:
1044             if (al->adapted_request) {
1045                 SBuf s = al->adapted_request->url.path();
1046                 out = s.c_str();
1047                 quote = 1;
1048             }
1049             break;
1050
1051         case LFT_SERVER_REQ_VERSION:
1052             if (al->adapted_request) {
1053                 snprintf(tmp, sizeof(tmp), "%d.%d",
1054                          (int) al->adapted_request->http_ver.major,
1055                          (int) al->adapted_request->http_ver.minor);
1056                 out = tmp;
1057             }
1058             break;
1059
1060         case LFT_CLIENT_REQUEST_SIZE_TOTAL:
1061             outoff = al->http.clientRequestSz.messageTotal();
1062             dooff = 1;
1063             break;
1064
1065         case LFT_CLIENT_REQUEST_SIZE_HEADERS:
1066             outoff = al->http.clientRequestSz.header;
1067             dooff =1;
1068             break;
1069
1070         /*case LFT_REQUEST_SIZE_BODY: */
1071         /*case LFT_REQUEST_SIZE_BODY_NO_TE: */
1072
1073         case LFT_ADAPTED_REPLY_SIZE_TOTAL:
1074             outoff = al->http.clientReplySz.messageTotal();
1075             dooff = 1;
1076             break;
1077
1078         case LFT_REPLY_HIGHOFFSET:
1079             outoff = al->cache.highOffset;
1080
1081             dooff = 1;
1082
1083             break;
1084
1085         case LFT_REPLY_OBJECTSIZE:
1086             outoff = al->cache.objectSize;
1087
1088             dooff = 1;
1089
1090             break;
1091
1092         case LFT_ADAPTED_REPLY_SIZE_HEADERS:
1093             outint = al->http.clientReplySz.header;
1094             doint = 1;
1095             break;
1096
1097         /*case LFT_REPLY_SIZE_BODY: */
1098         /*case LFT_REPLY_SIZE_BODY_NO_TE: */
1099
1100         case LFT_CLIENT_IO_SIZE_TOTAL:
1101             outint = al->http.clientRequestSz.messageTotal() + al->http.clientReplySz.messageTotal();
1102             doint = 1;
1103             break;
1104         /*case LFT_SERVER_IO_SIZE_TOTAL: */
1105
1106         case LFT_TAG:
1107             if (al->request)
1108                 out = al->request->tag.termedBuf();
1109
1110             quote = 1;
1111
1112             break;
1113
1114         case LFT_EXT_LOG:
1115             if (al->request)
1116                 out = al->request->extacl_log.termedBuf();
1117
1118             quote = 1;
1119
1120             break;
1121
1122         case LFT_SEQUENCE_NUMBER:
1123             outoff = logSequenceNumber;
1124             dooff = 1;
1125             break;
1126
1127 #if USE_OPENSSL
1128         case LFT_SSL_BUMP_MODE: {
1129             const Ssl::BumpMode mode = static_cast<Ssl::BumpMode>(al->ssl.bumpMode);
1130             // for Ssl::bumpEnd, Ssl::bumpMode() returns NULL and we log '-'
1131             out = Ssl::bumpMode(mode);
1132             break;
1133         }
1134
1135         case LFT_SSL_USER_CERT_SUBJECT:
1136             if (X509 *cert = al->cache.sslClientCert.get()) {
1137                 if (X509_NAME *subject = X509_get_subject_name(cert)) {
1138                     X509_NAME_oneline(subject, tmp, sizeof(tmp));
1139                     out = tmp;
1140                 }
1141             }
1142             break;
1143
1144         case LFT_SSL_USER_CERT_ISSUER:
1145             if (X509 *cert = al->cache.sslClientCert.get()) {
1146                 if (X509_NAME *issuer = X509_get_issuer_name(cert)) {
1147                     X509_NAME_oneline(issuer, tmp, sizeof(tmp));
1148                     out = tmp;
1149                 }
1150             }
1151             break;
1152         case LFT_SSL_CLIENT_SNI:
1153             if (al->request && al->request->clientConnectionManager.valid()) {
1154                 if (Ssl::ServerBump * srvBump = al->request->clientConnectionManager->serverBump()) {
1155                     if (!srvBump->clientSni.isEmpty())
1156                         out = srvBump->clientSni.c_str();
1157                 }
1158             }
1159             break;
1160
1161         case LFT_SSL_SERVER_CERT_ISSUER:
1162         case LFT_SSL_SERVER_CERT_SUBJECT:
1163             // Not implemented
1164             break;
1165 #endif
1166
1167         case LFT_REQUEST_URLGROUP_OLD_2X:
1168             assert(LFT_REQUEST_URLGROUP_OLD_2X == 0); // should never happen.
1169
1170         case LFT_NOTE:
1171             tmp[0] = fmt->data.header.separator;
1172             tmp[1] = '\0';
1173             if (fmt->data.header.header && *fmt->data.header.header) {
1174                 const char *separator = tmp;
1175 #if USE_ADAPTATION
1176                 Adaptation::History::Pointer ah = al->request ? al->request->adaptHistory() : Adaptation::History::Pointer();
1177                 if (ah != NULL && ah->metaHeaders != NULL) {
1178                     if (const char *meta = ah->metaHeaders->find(fmt->data.header.header, separator))
1179                         sb.append(meta);
1180                 }
1181 #endif
1182                 if (al->notes != NULL) {
1183                     if (const char *note = al->notes->find(fmt->data.header.header, separator)) {
1184                         if (sb.size())
1185                             sb.append(separator);
1186                         sb.append(note);
1187                     }
1188                 }
1189                 out = sb.termedBuf();
1190                 quote = 1;
1191             } else {
1192                 // if no argument given use default "\r\n" as notes separator
1193                 const char *separator = fmt->data.string ? tmp : "\r\n";
1194 #if USE_ADAPTATION
1195                 Adaptation::History::Pointer ah = al->request ? al->request->adaptHistory() : Adaptation::History::Pointer();
1196                 if (ah != NULL && ah->metaHeaders != NULL && !ah->metaHeaders->empty())
1197                     sb.append(ah->metaHeaders->toString(separator));
1198 #endif
1199                 if (al->notes != NULL && !al->notes->empty())
1200                     sb.append(al->notes->toString(separator));
1201
1202                 out = sb.termedBuf();
1203                 quote = 1;
1204             }
1205             break;
1206
1207         case LFT_CREDENTIALS:
1208 #if USE_AUTH
1209             if (al->request && al->request->auth_user_request != NULL)
1210                 out = strOrNull(al->request->auth_user_request->credentialsStr());
1211 #endif
1212
1213             break;
1214
1215         case LFT_PERCENT:
1216             out = "%";
1217             break;
1218
1219         // XXX: external_acl_type format tokens which are not output by logformat.
1220         // They are listed here because the switch requires
1221         // every ByteCode_t to be explicitly enumerated.
1222         // But do not output due to lack of access to the values.
1223         case LFT_EXT_ACL_USER_CERT_RAW:
1224         case LFT_EXT_ACL_USER_CERTCHAIN_RAW:
1225         case LFT_EXT_ACL_USER_CERT:
1226         case LFT_EXT_ACL_USER_CA_CERT:
1227         case LFT_EXT_ACL_CLIENT_EUI48:
1228         case LFT_EXT_ACL_CLIENT_EUI64:
1229         case LFT_EXT_ACL_NAME:
1230         case LFT_EXT_ACL_DATA:
1231             break;
1232         }
1233
1234         if (dooff) {
1235             snprintf(tmp, sizeof(tmp), "%0*" PRId64, fmt->zero && fmt->widthMin >= 0 ? fmt->widthMin : 0, outoff);
1236             out = tmp;
1237
1238         } else if (doint) {
1239             snprintf(tmp, sizeof(tmp), "%0*ld", fmt->zero && fmt->widthMin >= 0 ? fmt->widthMin : 0, outint);
1240             out = tmp;
1241         } else if (doMsec) {
1242             if (fmt->widthMax < 0) {
1243                 snprintf(tmp, sizeof(tmp), "%0*ld", fmt->widthMin , tvToMsec(outtv));
1244             } else {
1245                 int precision = fmt->widthMax;
1246                 snprintf(tmp, sizeof(tmp), "%0*" PRId64 ".%0*" PRId64 "", fmt->zero && (fmt->widthMin - precision - 1 >= 0) ? fmt->widthMin - precision - 1 : 0, static_cast<int64_t>(outtv.tv_sec * 1000 + outtv.tv_usec / 1000), precision, static_cast<int64_t>((outtv.tv_usec % 1000 )* (1000 / fmt->divisor)));
1247             }
1248             out = tmp;
1249         } else if (doSec) {
1250             int precision = fmt->widthMax >=0 ? fmt->widthMax :3;
1251             snprintf(tmp, sizeof(tmp), "%0*" PRId64 ".%0*d", fmt->zero && (fmt->widthMin - precision - 1 >= 0) ? fmt->widthMin - precision - 1 : 0, static_cast<int64_t>(outtv.tv_sec), precision, (int)(outtv.tv_usec / fmt->divisor));
1252             out = tmp;
1253         }
1254
1255         if (out && *out) {
1256             if (quote || fmt->quote != LOG_QUOTE_NONE) {
1257                 char *newout = NULL;
1258                 int newfree = 0;
1259
1260                 switch (fmt->quote) {
1261
1262                 case LOG_QUOTE_NONE:
1263                     newout = rfc1738_escape_unescaped(out);
1264                     break;
1265
1266                 case LOG_QUOTE_QUOTES: {
1267                     size_t out_len = static_cast<size_t>(strlen(out)) * 2 + 1;
1268                     if (out_len >= sizeof(tmp)) {
1269                         newout = (char *)xmalloc(out_len);
1270                         newfree = 1;
1271                     } else
1272                         newout = tmp;
1273                     log_quoted_string(out, newout);
1274                 }
1275                 break;
1276
1277                 case LOG_QUOTE_MIMEBLOB:
1278                     newout = QuoteMimeBlob(out);
1279                     newfree = 1;
1280                     break;
1281
1282                 case LOG_QUOTE_URL:
1283                     newout = rfc1738_escape(out);
1284                     break;
1285
1286                 case LOG_QUOTE_RAW:
1287                     break;
1288                 }
1289
1290                 if (newout) {
1291                     if (dofree)
1292                         safe_free(out);
1293
1294                     out = newout;
1295
1296                     dofree = newfree;
1297                 }
1298             }
1299
1300             // enforce width limits if configured
1301             const bool haveMaxWidth = fmt->widthMax >=0 && !doint && !dooff && !doMsec && !doSec;
1302             if (haveMaxWidth || fmt->widthMin) {
1303                 const int minWidth = fmt->widthMin >= 0 ?
1304                                      fmt->widthMin :0;
1305                 const int maxWidth = haveMaxWidth ?
1306                                      fmt->widthMax : strlen(out);
1307
1308                 if (fmt->left)
1309                     mb.appendf("%-*.*s", minWidth, maxWidth, out);
1310                 else
1311                     mb.appendf("%*.*s", minWidth, maxWidth, out);
1312             } else
1313                 mb.append(out, strlen(out));
1314         } else {
1315             mb.append("-", 1);
1316         }
1317
1318         if (fmt->space)
1319             mb.append(" ", 1);
1320
1321         sb.clean();
1322
1323         if (dofree)
1324             safe_free(out);
1325     }
1326 }
1327