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         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             if (al->http.timedout || al->http.aborted) {
 881                 snprintf(tmp, sizeof(tmp), "%s%s", LogTags_str[al->cache.code],
 882                          al->http.statusSfx());
 883                 out = tmp;
 884             } else {
 885                 out = LogTags_str[al->cache.code];
 886             }
 887
 888             break;
 889
 890         case LFT_SQUID_ERROR:
 891             if (al->request && al->request->errType != ERR_NONE)
 892                 out = errorPageName(al->request->errType);
 893             break;
 894
 895         case LFT_SQUID_ERROR_DETAIL:
 896 #if USE_OPENSSL
 897             if (al->request && al->request->errType == ERR_SECURE_CONNECT_FAIL) {
 898                 if (! (out = Ssl::GetErrorName(al->request->errDetail))) {
 899                     snprintf(tmp, sizeof(tmp), "SSL_ERR=%d", al->request->errDetail);
 900                     out = tmp;
 901                 }
 902             } else
 903 #endif
 904                 if (al->request && al->request->errDetail != ERR_DETAIL_NONE) {
 905                     if (al->request->errDetail > ERR_DETAIL_START  &&
 906                             al->request->errDetail < ERR_DETAIL_MAX)
 907                         out = errorDetailName(al->request->errDetail);
 908                     else {
 909                         if (al->request->errDetail >= ERR_DETAIL_EXCEPTION_START)
 910                             snprintf(tmp, sizeof(tmp), "%s=0x%X",
 911                                      errorDetailName(al->request->errDetail), (uint32_t) al->request->errDetail);
 912                         else
 913                             snprintf(tmp, sizeof(tmp), "%s=%d",
 914                                      errorDetailName(al->request->errDetail), al->request->errDetail);
 915                         out = tmp;
 916                     }
 917                 }
 918             break;
 919
 920         case LFT_SQUID_HIERARCHY:
 921             if (al->hier.ping.timedout)
 922                 mb.append("TIMEOUT_", 8);
 923
 924             out = hier_code_str[al->hier.code];
 925
 926             break;
 927
 928         case LFT_MIME_TYPE:
 929             out = al->http.content_type;
 930
 931             break;
 932
 933         case LFT_CLIENT_REQ_METHOD:
 934             if (al->request) {
 935                 const SBuf &s = al->request->method.image();
 936                 sb.append(s.rawContent(), s.length());
 937                 out = sb.termedBuf();
 938                 quote = 1;
 939             }
 940             break;
 941
 942         case LFT_CLIENT_REQ_URI:
 943             // original client URI
 944             if (al->request) {
 945                 out = urlCanonical(al->request);
 946                 quote = 1;
 947             }
 948             break;
 949
 950         case LFT_CLIENT_REQ_URLSCHEME:
 951             if (al->request) {
 952                 out = al->request->url.getScheme().c_str();
 953                 quote = 1;
 954             }
 955             break;
 956
 957         case LFT_CLIENT_REQ_URLDOMAIN:
 958             if (al->request) {
 959                 out = al->request->GetHost();
 960                 quote = 1;
 961             }
 962             break;
 963
 964         case LFT_CLIENT_REQ_URLPORT:
 965             if (al->request) {
 966                 outint = al->request->port;
 967                 doint = 1;
 968             }
 969             break;
 970
 971         case LFT_REQUEST_URLPATH_OLD_31:
 972         case LFT_CLIENT_REQ_URLPATH:
 973             if (al->request) {
 974                 out = al->request->urlpath.termedBuf();
 975                 quote = 1;
 976             }
 977             break;
 978
 979         case LFT_CLIENT_REQ_VERSION:
 980             if (al->request) {
 981                 snprintf(tmp, sizeof(tmp), "%d.%d", (int) al->request->http_ver.major, (int) al->request->http_ver.minor);
 982                 out = tmp;
 983             }
 984             break;
 985
 986         case LFT_REQUEST_METHOD:
 987             if (al->_private.method_str) // ICP, HTCP method code
 988                 out = al->_private.method_str;
 989             else {
 990                 const SBuf &s = al->http.method.image();
 991                 sb.append(s.rawContent(), s.length());
 992                 out = sb.termedBuf();
 993                 quote = 1;
 994             }
 995             break;
 996
 997         case LFT_REQUEST_URI:
 998             out = al->url;
 999             break;
1000
1001         case LFT_REQUEST_VERSION_OLD_2X:
1002         case LFT_REQUEST_VERSION:
1003             snprintf(tmp, sizeof(tmp), "%d.%d", (int) al->http.version.major, (int) al->http.version.minor);
1004             out = tmp;
1005             break;
1006
1007         case LFT_SERVER_REQ_METHOD:
1008             if (al->adapted_request) {
1009                 const SBuf &s = al->adapted_request->method.image();
1010                 sb.append(s.rawContent(), s.length());
1011                 out = sb.termedBuf();
1012                 quote = 1;
1013             }
1014             break;
1015
1016         case LFT_SERVER_REQ_URI:
1017             // adapted request URI sent to server/peer
1018             if (al->adapted_request) {
1019                 out = urlCanonical(al->adapted_request);
1020                 quote = 1;
1021             }
1022             break;
1023
1024         case LFT_SERVER_REQ_URLSCHEME:
1025             if (al->adapted_request) {
1026                 out = al->adapted_request->url.getScheme().c_str();
1027                 quote = 1;
1028             }
1029             break;
1030
1031         case LFT_SERVER_REQ_URLDOMAIN:
1032             if (al->adapted_request) {
1033                 out = al->adapted_request->GetHost();
1034                 quote = 1;
1035             }
1036             break;
1037
1038         case LFT_SERVER_REQ_URLPORT:
1039             if (al->adapted_request) {
1040                 outint = al->adapted_request->port;
1041                 doint = 1;
1042             }
1043             break;
1044
1045         case LFT_SERVER_REQ_URLPATH:
1046             if (al->adapted_request) {
1047                 out = al->adapted_request->urlpath.termedBuf();
1048                 quote = 1;
1049             }
1050             break;
1051
1052         case LFT_SERVER_REQ_VERSION:
1053             if (al->adapted_request) {
1054                 snprintf(tmp, sizeof(tmp), "%d.%d",
1055                          (int) al->adapted_request->http_ver.major,
1056                          (int) al->adapted_request->http_ver.minor);
1057                 out = tmp;
1058             }
1059             break;
1060
1061         case LFT_CLIENT_REQUEST_SIZE_TOTAL:
1062             outoff = al->http.clientRequestSz.messageTotal();
1063             dooff = 1;
1064             break;
1065
1066         case LFT_CLIENT_REQUEST_SIZE_HEADERS:
1067             outoff = al->http.clientRequestSz.header;
1068             dooff =1;
1069             break;
1070
1071         /*case LFT_REQUEST_SIZE_BODY: */
1072         /*case LFT_REQUEST_SIZE_BODY_NO_TE: */
1073
1074         case LFT_ADAPTED_REPLY_SIZE_TOTAL:
1075             outoff = al->http.clientReplySz.messageTotal();
1076             dooff = 1;
1077             break;
1078
1079         case LFT_REPLY_HIGHOFFSET:
1080             outoff = al->cache.highOffset;
1081
1082             dooff = 1;
1083
1084             break;
1085
1086         case LFT_REPLY_OBJECTSIZE:
1087             outoff = al->cache.objectSize;
1088
1089             dooff = 1;
1090
1091             break;
1092
1093         case LFT_ADAPTED_REPLY_SIZE_HEADERS:
1094             outint = al->http.clientReplySz.header;
1095             doint = 1;
1096             break;
1097
1098         /*case LFT_REPLY_SIZE_BODY: */
1099         /*case LFT_REPLY_SIZE_BODY_NO_TE: */
1100
1101         case LFT_CLIENT_IO_SIZE_TOTAL:
1102             outint = al->http.clientRequestSz.messageTotal() + al->http.clientReplySz.messageTotal();
1103             doint = 1;
1104             break;
1105         /*case LFT_SERVER_IO_SIZE_TOTAL: */
1106
1107         case LFT_TAG:
1108             if (al->request)
1109                 out = al->request->tag.termedBuf();
1110
1111             quote = 1;
1112
1113             break;
1114
1115         case LFT_EXT_LOG:
1116             if (al->request)
1117                 out = al->request->extacl_log.termedBuf();
1118
1119             quote = 1;
1120
1121             break;
1122
1123         case LFT_SEQUENCE_NUMBER:
1124             outoff = logSequenceNumber;
1125             dooff = 1;
1126             break;
1127
1128 #if USE_OPENSSL
1129         case LFT_SSL_BUMP_MODE: {
1130             const Ssl::BumpMode mode = static_cast<Ssl::BumpMode>(al->ssl.bumpMode);
1131             // for Ssl::bumpEnd, Ssl::bumpMode() returns NULL and we log '-'
1132             out = Ssl::bumpMode(mode);
1133             break;
1134         }
1135
1136         case LFT_SSL_USER_CERT_SUBJECT:
1137             if (X509 *cert = al->cache.sslClientCert.get()) {
1138                 if (X509_NAME *subject = X509_get_subject_name(cert)) {
1139                     X509_NAME_oneline(subject, tmp, sizeof(tmp));
1140                     out = tmp;
1141                 }
1142             }
1143             break;
1144
1145         case LFT_SSL_USER_CERT_ISSUER:
1146             if (X509 *cert = al->cache.sslClientCert.get()) {
1147                 if (X509_NAME *issuer = X509_get_issuer_name(cert)) {
1148                     X509_NAME_oneline(issuer, tmp, sizeof(tmp));
1149                     out = tmp;
1150                 }
1151             }
1152             break;
1153         case LFT_SSL_CLIENT_SNI:
1154             if (al->request && al->request->clientConnectionManager.valid()) {
1155                 if (Ssl::ServerBump * srvBump = al->request->clientConnectionManager->serverBump()) {
1156                     if (!srvBump->clientSni.isEmpty())
1157                         out = srvBump->clientSni.c_str();
1158                 }
1159             }
1160             break;
1161
1162         case LFT_SSL_SERVER_CERT_ISSUER:
1163         case LFT_SSL_SERVER_CERT_SUBJECT:
1164             // Not implemented
1165             break;
1166 #endif
1167
1168         case LFT_REQUEST_URLGROUP_OLD_2X:
1169             assert(LFT_REQUEST_URLGROUP_OLD_2X == 0); // should never happen.
1170
1171         case LFT_NOTE:
1172             tmp[0] = fmt->data.header.separator;
1173             tmp[1] = '\0';
1174             if (fmt->data.header.header && *fmt->data.header.header) {
1175                 const char *separator = tmp;
1176 #if USE_ADAPTATION
1177                 Adaptation::History::Pointer ah = al->request ? al->request->adaptHistory() : Adaptation::History::Pointer();
1178                 if (ah != NULL && ah->metaHeaders != NULL) {
1179                     if (const char *meta = ah->metaHeaders->find(fmt->data.header.header, separator))
1180                         sb.append(meta);
1181                 }
1182 #endif
1183                 if (al->notes != NULL) {
1184                     if (const char *note = al->notes->find(fmt->data.header.header, separator)) {
1185                         if (sb.size())
1186                             sb.append(separator);
1187                         sb.append(note);
1188                     }
1189                 }
1190                 out = sb.termedBuf();
1191                 quote = 1;
1192             } else {
1193                 // if no argument given use default "\r\n" as notes separator
1194                 const char *separator = fmt->data.string ? tmp : "\r\n";
1195 #if USE_ADAPTATION
1196                 Adaptation::History::Pointer ah = al->request ? al->request->adaptHistory() : Adaptation::History::Pointer();
1197                 if (ah != NULL && ah->metaHeaders != NULL && !ah->metaHeaders->empty())
1198                     sb.append(ah->metaHeaders->toString(separator));
1199 #endif
1200                 if (al->notes != NULL && !al->notes->empty())
1201                     sb.append(al->notes->toString(separator));
1202
1203                 out = sb.termedBuf();
1204                 quote = 1;
1205             }
1206             break;
1207
1208         case LFT_CREDENTIALS:
1209 #if USE_AUTH
1210             if (al->request && al->request->auth_user_request != NULL)
1211                 out = strOrNull(al->request->auth_user_request->credentialsStr());
1212 #endif
1213
1214             break;
1215
1216         case LFT_PERCENT:
1217             out = "%";
1218             break;
1219
1220         // XXX: external_acl_type format tokens which are not output by logformat.
1221         // They are listed here because the switch requires
1222         // every ByteCode_t to be explicitly enumerated.
1223         // But do not output due to lack of access to the values.
1224         case LFT_EXT_ACL_USER_CERT_RAW:
1225         case LFT_EXT_ACL_USER_CERTCHAIN_RAW:
1226         case LFT_EXT_ACL_USER_CERT:
1227         case LFT_EXT_ACL_USER_CA_CERT:
1228         case LFT_EXT_ACL_CLIENT_EUI48:
1229         case LFT_EXT_ACL_CLIENT_EUI64:
1230         case LFT_EXT_ACL_NAME:
1231         case LFT_EXT_ACL_DATA:
1232             break;
1233         }
1234
1235         if (dooff) {
1236             snprintf(tmp, sizeof(tmp), "%0*" PRId64, fmt->zero && fmt->widthMin >= 0 ? fmt->widthMin : 0, outoff);
1237             out = tmp;
1238
1239         } else if (doint) {
1240             snprintf(tmp, sizeof(tmp), "%0*ld", fmt->zero && fmt->widthMin >= 0 ? fmt->widthMin : 0, outint);
1241             out = tmp;
1242         } else if (doMsec) {
1243             if (fmt->widthMax < 0) {
1244                 snprintf(tmp, sizeof(tmp), "%0*ld", fmt->widthMin , tvToMsec(outtv));
1245             } else {
1246                 int precision = fmt->widthMax;
1247                 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)));
1248             }
1249             out = tmp;
1250         } else if (doSec) {
1251             int precision = fmt->widthMax >=0 ? fmt->widthMax :3;
1252             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));
1253             out = tmp;
1254         }
1255
1256         if (out && *out) {
1257             if (quote || fmt->quote != LOG_QUOTE_NONE) {
1258                 char *newout = NULL;
1259                 int newfree = 0;
1260
1261                 switch (fmt->quote) {
1262
1263                 case LOG_QUOTE_NONE:
1264                     newout = rfc1738_escape_unescaped(out);
1265                     break;
1266
1267                 case LOG_QUOTE_QUOTES: {
1268                     size_t out_len = static_cast<size_t>(strlen(out)) * 2 + 1;
1269                     if (out_len >= sizeof(tmp)) {
1270                         newout = (char *)xmalloc(out_len);
1271                         newfree = 1;
1272                     } else
1273                         newout = tmp;
1274                     log_quoted_string(out, newout);
1275                 }
1276                 break;
1277
1278                 case LOG_QUOTE_MIMEBLOB:
1279                     newout = QuoteMimeBlob(out);
1280                     newfree = 1;
1281                     break;
1282
1283                 case LOG_QUOTE_URL:
1284                     newout = rfc1738_escape(out);
1285                     break;
1286
1287                 case LOG_QUOTE_RAW:
1288                     break;
1289                 }
1290
1291                 if (newout) {
1292                     if (dofree)
1293                         safe_free(out);
1294
1295                     out = newout;
1296
1297                     dofree = newfree;
1298                 }
1299             }
1300
1301             // enforce width limits if configured
1302             const bool haveMaxWidth = fmt->widthMax >=0 && !doint && !dooff && !doMsec && !doSec;
1303             if (haveMaxWidth || fmt->widthMin) {
1304                 const int minWidth = fmt->widthMin >= 0 ?
1305                                      fmt->widthMin :0;
1306                 const int maxWidth = haveMaxWidth ?
1307                                      fmt->widthMax : strlen(out);
1308
1309                 if (fmt->left)
1310                     mb.Printf("%-*.*s", minWidth, maxWidth, out);
1311                 else
1312                     mb.Printf("%*.*s", minWidth, maxWidth, out);
1313             } else
1314                 mb.append(out, strlen(out));
1315         } else {
1316             mb.append("-", 1);
1317         }
1318
1319         if (fmt->space)
1320             mb.append(" ", 1);
1321
1322         sb.clean();
1323
1324         if (dofree)
1325             safe_free(out);
1326     }
1327 }
1328