src/format/Token.cc

   1 #include "squid.h"
   2 #include "format/Config.h"
   3 #include "format/Token.h"
   4 #include "format/TokenTableEntry.h"
   5 #include "globals.h"
   6 #include "SquidConfig.h"
   7 #include "Store.h"
   8
   9 const char *Format::log_tags[] = {
  10     "NONE",
  11     "TCP_HIT",
  12     "TCP_MISS",
  13     "TCP_REFRESH_UNMODIFIED",
  14     "TCP_REFRESH_FAIL", // same tag logged for LOG_TCP_REFRESH_FAIL_OLD and
  15     "TCP_REFRESH_FAIL", // LOG_TCP_REFRESH_FAIL_ERR for backward-compatibility
  16     "TCP_REFRESH_MODIFIED",
  17     "TCP_CLIENT_REFRESH_MISS",
  18     "TCP_IMS_HIT",
  19     "TCP_SWAPFAIL_MISS",
  20     "TCP_NEGATIVE_HIT",
  21     "TCP_MEM_HIT",
  22     "TCP_DENIED",
  23     "TCP_DENIED_REPLY",
  24     "TCP_OFFLINE_HIT",
  25     "TCP_REDIRECT",
  26     "UDP_HIT",
  27     "UDP_MISS",
  28     "UDP_DENIED",
  29     "UDP_INVALID",
  30     "UDP_MISS_NOFETCH",
  31     "ICP_QUERY",
  32     "LOG_TYPE_MAX"
  33 };
  34
  35 // Due to token overlaps between 1 and 2 letter tokens (Bug 3310)
  36 // We split the token table into sets determined by the token length
  37 namespace Format
  38 {
  39
  40 /// 1-char tokens.
  41 static TokenTableEntry TokenTable1C[] = {
  42
  43     {">a", LFT_CLIENT_IP_ADDRESS},
  44     {">p", LFT_CLIENT_PORT},
  45     {">A", LFT_CLIENT_FQDN},
  46
  47     {"<a", LFT_SERVER_IP_ADDRESS},
  48     {"<p", LFT_SERVER_PORT},
  49     {"<A", LFT_SERVER_FQDN_OR_PEER_NAME},
  50
  51     {">h", LFT_REQUEST_HEADER},
  52     {">h", LFT_REQUEST_ALL_HEADERS},
  53     {"<h", LFT_REPLY_HEADER},
  54     {"<h", LFT_REPLY_ALL_HEADERS},
  55
  56     {">v", LFT_REQUEST_VERSION_OLD_2X},
  57
  58     {"%", LFT_PERCENT},
  59
  60     {NULL, LFT_NONE}            /* this must be last */
  61 };
  62
  63 /// 2-char tokens
  64 static TokenTableEntry TokenTable2C[] = {
  65
  66     {">la", LFT_CLIENT_LOCAL_IP},
  67     {"la", LFT_LOCAL_LISTENING_IP},
  68     {">lp", LFT_CLIENT_LOCAL_PORT},
  69     {"lp", LFT_LOCAL_LISTENING_PORT},
  70     /*{ "lA", LFT_LOCAL_NAME }, */
  71
  72     {"<la", LFT_SERVER_LOCAL_IP},
  73     {"oa", LFT_SERVER_LOCAL_IP_OLD_27},
  74     {"<lp", LFT_SERVER_LOCAL_PORT},
  75     /* {"ot", LFT_PEER_OUTGOING_TOS}, */
  76
  77     {"ts", LFT_TIME_SECONDS_SINCE_EPOCH},
  78     {"tu", LFT_TIME_SUBSECOND},
  79     {"tl", LFT_TIME_LOCALTIME},
  80     {"tg", LFT_TIME_GMT},
  81     {"tr", LFT_TIME_TO_HANDLE_REQUEST},
  82
  83     {"<pt", LFT_PEER_RESPONSE_TIME},
  84     {"<tt", LFT_TOTAL_SERVER_SIDE_RESPONSE_TIME},
  85     {"dt", LFT_DNS_WAIT_TIME},
  86
  87     {">ha", LFT_ADAPTED_REQUEST_HEADER},
  88     {">ha", LFT_ADAPTED_REQUEST_ALL_HEADERS},
  89
  90     {"un", LFT_USER_NAME},
  91     {"ul", LFT_USER_LOGIN},
  92     /*{ "ur", LFT_USER_REALM }, */
  93     /*{ "us", LFT_USER_SCHEME }, */
  94     {"ui", LFT_USER_IDENT},
  95     {"ue", LFT_USER_EXTERNAL},
  96
  97     {"Hs", LFT_HTTP_SENT_STATUS_CODE_OLD_30},
  98     {">Hs", LFT_HTTP_SENT_STATUS_CODE},
  99     {"<Hs", LFT_HTTP_RECEIVED_STATUS_CODE},
 100     /*{ "Ht", LFT_HTTP_STATUS }, */
 101     {"<bs", LFT_HTTP_BODY_BYTES_READ},
 102
 103     {"Ss", LFT_SQUID_STATUS},
 104     {"Sh", LFT_SQUID_HIERARCHY},
 105
 106     {"mt", LFT_MIME_TYPE},
 107
 108     {">rm", LFT_CLIENT_REQ_METHOD},
 109     {">ru", LFT_CLIENT_REQ_URI},
 110     {">rp", LFT_CLIENT_REQ_URLPATH},
 111     /*{">rq", LFT_CLIENT_REQ_QUERY},*/
 112     {">rv", LFT_CLIENT_REQ_VERSION},
 113
 114     {"rm", LFT_REQUEST_METHOD},
 115     {"ru", LFT_REQUEST_URI},    /* doesn't include the query-string */
 116     {"rp", LFT_REQUEST_URLPATH_OLD_31},
 117     /* { "rq", LFT_REQUEST_QUERY }, * /     / * the query-string, INCLUDING the leading ? */
 118     {"rv", LFT_REQUEST_VERSION},
 119
 120     {"<rm", LFT_SERVER_REQ_METHOD},
 121     {"<ru", LFT_SERVER_REQ_URI},
 122     {"<rp", LFT_SERVER_REQ_URLPATH},
 123     /*{"<rq", LFT_SERVER_REQ_QUERY},*/
 124     {"<rv", LFT_SERVER_REQ_VERSION},
 125
 126     {">st", LFT_REQUEST_SIZE_TOTAL },
 127     /*{ ">sl", LFT_REQUEST_SIZE_LINE }, * / / * the request line "GET ... " */
 128     {">sh", LFT_REQUEST_SIZE_HEADERS },
 129     /*{ ">sb", LFT_REQUEST_SIZE_BODY }, */
 130     /*{ ">sB", LFT_REQUEST_SIZE_BODY_NO_TE }, */
 131
 132     {"<st", LFT_REPLY_SIZE_TOTAL},
 133     {"<sH", LFT_REPLY_HIGHOFFSET},
 134     {"<sS", LFT_REPLY_OBJECTSIZE},
 135     /*{ "<sl", LFT_REPLY_SIZE_LINE }, * /   / * the reply line (protocol, code, text) */
 136     {"<sh", LFT_REPLY_SIZE_HEADERS },
 137     /*{ "<sb", LFT_REPLY_SIZE_BODY }, */
 138     /*{ "<sB", LFT_REPLY_SIZE_BODY_NO_TE }, */
 139
 140     {"et", LFT_TAG},
 141     {"st", LFT_IO_SIZE_TOTAL},
 142     {"ea", LFT_EXT_LOG},
 143     {"sn", LFT_SEQUENCE_NUMBER},
 144
 145     {NULL, LFT_NONE}            /* this must be last */
 146 };
 147
 148 /// Miscellaneous >2 byte tokens
 149 static TokenTableEntry TokenTableMisc[] = {
 150     {">eui", LFT_CLIENT_EUI},
 151     {"err_code", LFT_SQUID_ERROR },
 152     {"err_detail", LFT_SQUID_ERROR_DETAIL },
 153     {"note", LFT_NOTE },
 154     {NULL, LFT_NONE}            /* this must be last */
 155 };
 156
 157 #if USE_ADAPTATION
 158 static TokenTableEntry TokenTableAdapt[] = {
 159     {"all_trs", LFT_ADAPTATION_ALL_XACT_TIMES},
 160     {"sum_trs", LFT_ADAPTATION_SUM_XACT_TIMES},
 161     {"<last_h", LFT_ADAPTATION_LAST_HEADER},
 162     {NULL, LFT_NONE}           /* this must be last */
 163 };
 164 #endif
 165
 166 #if ICAP_CLIENT
 167 /// ICAP (icap::) tokens
 168 static TokenTableEntry TokenTableIcap[] = {
 169     {"tt", LFT_ICAP_TOTAL_TIME},
 170     {"<last_h", LFT_ADAPTATION_LAST_HEADER}, // deprecated
 171
 172     {"<A",  LFT_ICAP_ADDR},
 173     {"<service_name",  LFT_ICAP_SERV_NAME},
 174     {"ru",  LFT_ICAP_REQUEST_URI},
 175     {"rm",  LFT_ICAP_REQUEST_METHOD},
 176     {">st", LFT_ICAP_BYTES_SENT},
 177     {"<st", LFT_ICAP_BYTES_READ},
 178     {"<bs", LFT_ICAP_BODY_BYTES_READ},
 179
 180     {">h",  LFT_ICAP_REQ_HEADER},
 181     {"<h",  LFT_ICAP_REP_HEADER},
 182
 183     {"tr",  LFT_ICAP_TR_RESPONSE_TIME},
 184     {"tio", LFT_ICAP_IO_TIME},
 185     {"to",  LFT_ICAP_OUTCOME},
 186     {"Hs",  LFT_ICAP_STATUS_CODE},
 187
 188     {NULL, LFT_NONE}           /* this must be last */
 189 };
 190 #endif
 191
 192 #if USE_SSL
 193 // SSL (ssl::) tokens
 194 static TokenTableEntry TokenTableSsl[] = {
 195     {"bump_mode", LFT_SSL_BUMP_MODE},
 196     {">cert_subject", LFT_SSL_USER_CERT_SUBJECT},
 197     {">cert_issuer", LFT_SSL_USER_CERT_ISSUER},
 198     {NULL, LFT_NONE}
 199 };
 200 #endif
 201 } // namespace Format
 202
 203 /// Register all components custom format tokens
 204 void
 205 Format::Token::Init()
 206 {
 207     // TODO standard log tokens
 208     // TODO external ACL fmt tokens
 209
 210 #if USE_ADAPTATION
 211     TheConfig.registerTokens(String("adapt"),::Format::TokenTableAdapt);
 212 #endif
 213 #if ICAP_CLIENT
 214     TheConfig.registerTokens(String("icap"),::Format::TokenTableIcap);
 215 #endif
 216 #if USE_SSL
 217     TheConfig.registerTokens(String("ssl"),::Format::TokenTableSsl);
 218 #endif
 219 }
 220
 221 /// Scans a token table to see if the next token exists there
 222 /// returns a pointer to next unparsed byte and updates type member if found
 223 const char *
 224 Format::Token::scanForToken(TokenTableEntry const table[], const char *cur)
 225 {
 226     for (TokenTableEntry const *lte = table; lte->configTag != NULL; ++lte) {
 227         debugs(46, 8, HERE << "compare tokens '" << lte->configTag << "' with '" << cur << "'");
 228         if (strncmp(lte->configTag, cur, strlen(lte->configTag)) == 0) {
 229             type = lte->tokenType;
 230             label = lte->configTag;
 231             debugs(46, 7, HERE << "Found token '" << label << "'");
 232             return cur + strlen(lte->configTag);
 233         }
 234     }
 235     return cur;
 236 }
 237
 238 /* parses a single token. Returns the token length in characters,
 239  * and fills in the lt item with the token information.
 240  * def is for sure null-terminated
 241  */
 242 int
 243 Format::Token::parse(const char *def, Quoting *quoting)
 244 {
 245     const char *cur = def;
 246
 247     int l;
 248
 249     l = strcspn(cur, "%");
 250
 251     if (l > 0) {
 252         char *cp;
 253         /* it's a string for sure, until \0 or the next % */
 254         cp = (char *)xmalloc(l + 1);
 255         xstrncpy(cp, cur, l + 1);
 256         type = LFT_STRING;
 257         data.string = cp;
 258
 259         while (l > 0) {
 260             switch (*cur) {
 261
 262             case '"':
 263
 264                 if (*quoting == LOG_QUOTE_NONE)
 265                     *quoting = LOG_QUOTE_QUOTES;
 266                 else if (*quoting == LOG_QUOTE_QUOTES)
 267                     *quoting = LOG_QUOTE_NONE;
 268
 269                 break;
 270
 271             case '[':
 272                 if (*quoting == LOG_QUOTE_NONE)
 273                     *quoting = LOG_QUOTE_MIMEBLOB;
 274
 275                 break;
 276
 277             case ']':
 278                 if (*quoting == LOG_QUOTE_MIMEBLOB)
 279                     *quoting = LOG_QUOTE_NONE;
 280
 281                 break;
 282             }
 283
 284             ++cur;
 285             --l;
 286         }
 287
 288         goto done;
 289     }
 290
 291     if (!*cur)
 292         goto done;
 293
 294     ++cur;
 295
 296     // select quoting style for his particular token
 297     switch (*cur) {
 298
 299     case '"':
 300         quote = LOG_QUOTE_QUOTES;
 301         ++cur;
 302         break;
 303
 304     case '\'':
 305         quote = LOG_QUOTE_RAW;
 306         ++cur;
 307         break;
 308
 309     case '[':
 310         quote = LOG_QUOTE_MIMEBLOB;
 311         ++cur;
 312         break;
 313
 314     case '#':
 315         quote = LOG_QUOTE_URL;
 316         ++cur;
 317         break;
 318
 319     default:
 320         quote = *quoting;
 321         break;
 322     }
 323
 324     if (*cur == '-') {
 325         left = 1;
 326         ++cur;
 327     }
 328
 329     if (*cur == '0') {
 330         zero = 1;
 331         ++cur;
 332     }
 333
 334     char *endp;
 335     if (xisdigit(*cur)) {
 336         widthMin = strtol(cur, &endp, 10);
 337         cur = endp;
 338     }
 339
 340     if (*cur == '.' && xisdigit(*(++cur))) {
 341         widthMax = strtol(cur, &endp, 10);
 342         cur = endp;
 343     }
 344
 345     if (*cur == '{') {
 346         char *cp;
 347         ++cur;
 348         l = strcspn(cur, "}");
 349         cp = (char *)xmalloc(l + 1);
 350         xstrncpy(cp, cur, l + 1);
 351         data.string = cp;
 352         cur += l;
 353
 354         if (*cur == '}')
 355             ++cur;
 356     }
 357
 358     type = LFT_NONE;
 359
 360     // Scan each registered token namespace
 361     debugs(46, 9, HERE << "check for token in " << TheConfig.tokens.size() << " namespaces.");
 362     for (std::list<TokenNamespace>::const_iterator itr = TheConfig.tokens.begin(); itr != TheConfig.tokens.end(); ++itr) {
 363         debugs(46, 7, HERE << "check for possible " << itr->prefix << ":: token");
 364         const size_t len = itr->prefix.size();
 365         if (itr->prefix.cmp(cur, len) == 0 && cur[len] == ':' && cur[len+1] == ':') {
 366             debugs(46, 5, HERE << "check for " << itr->prefix << ":: token in '" << cur << "'");
 367             const char *old = cur;
 368             cur = scanForToken(itr->tokenSet, cur+len+2);
 369             if (old != cur) // found
 370                 break;
 371             else // reset to start of namespace
 372                 cur = cur - len - 2;
 373         }
 374     }
 375
 376     if (type == LFT_NONE) {
 377         // For upward compatibility, assume "http::" prefix as default prefix
 378         // for all log access formatting codes, except those starting with a
 379         // "%" or a known namespace. (ie "icap::", "adapt::")
 380         if (strncmp(cur,"http::", 6) == 0 && *(cur+6) != '%' )
 381             cur += 6;
 382
 383         // NP: scan the sets of tokens in decreasing size to guarantee no
 384         //     mistakes made with overlapping names. (Bug 3310)
 385
 386         // Scan for various long tokens
 387         debugs(46, 5, HERE << "scan for possible Misc token");
 388         cur = scanForToken(TokenTableMisc, cur);
 389         // scan for 2-char tokens
 390         if (type == LFT_NONE) {
 391             debugs(46, 5, HERE << "scan for possible 2C token");
 392             cur = scanForToken(TokenTable2C, cur);
 393         }
 394         // finally scan for 1-char tokens.
 395         if (type == LFT_NONE) {
 396             debugs(46, 5, HERE << "scan for possible 1C token");
 397             cur = scanForToken(TokenTable1C, cur);
 398         }
 399     }
 400
 401     if (type == LFT_NONE) {
 402         fatalf("Can't parse configuration token: '%s'\n", def);
 403     }
 404
 405     if (*cur == ' ') {
 406         space = 1;
 407         ++cur;
 408     }
 409
 410 done:
 411
 412     switch (type) {
 413
 414 #if USE_ADAPTATION
 415     case LFT_ADAPTATION_LAST_HEADER:
 416 #endif
 417
 418 #if ICAP_CLIENT
 419     case LFT_ICAP_REQ_HEADER:
 420
 421     case LFT_ICAP_REP_HEADER:
 422 #endif
 423
 424     case LFT_ADAPTED_REQUEST_HEADER:
 425
 426     case LFT_REQUEST_HEADER:
 427
 428     case LFT_REPLY_HEADER:
 429
 430         if (data.string) {
 431             char *header = data.string;
 432             char *cp = strchr(header, ':');
 433
 434             if (cp) {
 435                 *cp = '\0';
 436                 ++cp;
 437
 438                 if (*cp == ',' || *cp == ';' || *cp == ':') {
 439                     data.header.separator = *cp;
 440                     ++cp;
 441                 } else {
 442                     data.header.separator = ',';
 443                 }
 444
 445                 data.header.element = cp;
 446
 447                 switch (type) {
 448                 case LFT_REQUEST_HEADER:
 449                     type = LFT_REQUEST_HEADER_ELEM;
 450                     break;
 451
 452                 case LFT_ADAPTED_REQUEST_HEADER:
 453                     type = LFT_ADAPTED_REQUEST_HEADER_ELEM;
 454                     break;
 455
 456                 case LFT_REPLY_HEADER:
 457                     type = LFT_REPLY_HEADER_ELEM;
 458                     break;
 459 #if USE_ADAPTATION
 460                 case LFT_ADAPTATION_LAST_HEADER:
 461                     type = LFT_ADAPTATION_LAST_HEADER_ELEM;
 462                     break;
 463 #endif
 464 #if ICAP_CLIENT
 465                 case LFT_ICAP_REQ_HEADER:
 466                     type = LFT_ICAP_REQ_HEADER_ELEM;
 467                     break;
 468                 case LFT_ICAP_REP_HEADER:
 469                     type = LFT_ICAP_REP_HEADER_ELEM;
 470                     break;
 471 #endif
 472                 default:
 473                     break;
 474                 }
 475             }
 476
 477             data.header.header = header;
 478         } else {
 479             switch (type) {
 480             case LFT_REQUEST_HEADER:
 481                 type = LFT_REQUEST_ALL_HEADERS;
 482                 break;
 483
 484             case LFT_ADAPTED_REQUEST_HEADER:
 485                 type = LFT_ADAPTED_REQUEST_ALL_HEADERS;
 486                 break;
 487
 488             case LFT_REPLY_HEADER:
 489                 type = LFT_REPLY_ALL_HEADERS;
 490                 break;
 491 #if USE_ADAPTATION
 492             case LFT_ADAPTATION_LAST_HEADER:
 493                 type = LFT_ADAPTATION_LAST_ALL_HEADERS;
 494                 break;
 495 #endif
 496 #if ICAP_CLIENT
 497             case LFT_ICAP_REQ_HEADER:
 498                 type = LFT_ICAP_REQ_ALL_HEADERS;
 499                 break;
 500             case LFT_ICAP_REP_HEADER:
 501                 type = LFT_ICAP_REP_ALL_HEADERS;
 502                 break;
 503 #endif
 504             default:
 505                 break;
 506             }
 507             Config.onoff.log_mime_hdrs = 1;
 508         }
 509
 510         break;
 511
 512     case LFT_CLIENT_FQDN:
 513         Config.onoff.log_fqdn = 1;
 514         break;
 515
 516     case LFT_TIME_SUBSECOND:
 517         divisor = 1000;
 518
 519         if (widthMax > 0) {
 520             int i;
 521             divisor = 1000000;
 522
 523             for (i = widthMax; i > 1; --i)
 524                 divisor /= 10;
 525
 526             if (!divisor)
 527                 divisor = 0;
 528         }
 529         break;
 530
 531     case LFT_HTTP_SENT_STATUS_CODE_OLD_30:
 532         debugs(46, DBG_PARSE_NOTE(DBG_IMPORTANT), "WARNING: The \"Hs\" formatting code is deprecated. Use the \">Hs\" instead.");
 533         type = LFT_HTTP_SENT_STATUS_CODE;
 534         break;
 535
 536     case LFT_SERVER_LOCAL_IP_OLD_27:
 537         debugs(46, DBG_PARSE_NOTE(DBG_IMPORTANT), "WARNING: The \"oa\" formatting code is deprecated. Use the \"<la\" instead.");
 538         type = LFT_SERVER_LOCAL_IP;
 539         break;
 540
 541     case LFT_REQUEST_URLPATH_OLD_31:
 542         debugs(46, DBG_PARSE_NOTE(DBG_IMPORTANT), "WARNING: The \"rp\" formatting code is deprecated. Use the \">rp\" instead.");
 543         type = LFT_CLIENT_REQ_URLPATH;
 544         break;
 545
 546     case LFT_REQUEST_VERSION_OLD_2X:
 547         debugs(46, DBG_PARSE_NOTE(DBG_IMPORTANT), "WARNING: The \">v\" formatting code is deprecated. Use the \">rv\" instead.");
 548         type = LFT_REQUEST_VERSION;
 549         break;
 550
 551 #if !USE_SQUID_EUI
 552     case LFT_CLIENT_EUI:
 553         debugs(46, DBG_CRITICAL, "WARNING: The \">eui\" formatting code requires EUI features which are disabled in this Squid.");
 554         break;
 555 #endif
 556
 557     default:
 558         break;
 559     }
 560
 561     return (cur - def);
 562 }
 563
 564 Format::Token::~Token()
 565 {
 566     label = NULL; // drop reference to global static.
 567     safe_free(data.string);
 568     while (next) {
 569         Token *tokens = next;
 570         next = next->next;
 571         tokens->next = NULL;
 572         delete tokens;
 573     }
 574 }
 575