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