blob: fa2042ccc76c2b457326157503141b6eec141592 [file] [log] [blame]
Willy Tarreau72c28532009-01-22 18:56:50 +01001/*
Willy Tarreaud8fc1102010-09-12 17:56:16 +02002 * haproxy log statistics reporter
Willy Tarreau72c28532009-01-22 18:56:50 +01003 *
Willy Tarreaud2201062010-05-27 18:17:30 +02004 * Copyright 2000-2010 Willy Tarreau <w@1wt.eu>
Willy Tarreau72c28532009-01-22 18:56:50 +01005 *
6 * This program is free software; you can redistribute it and/or
7 * modify it under the terms of the GNU General Public License
8 * as published by the Free Software Foundation; either version
9 * 2 of the License, or (at your option) any later version.
10 *
11 */
12
Willy Tarreau72c28532009-01-22 18:56:50 +010013#include <errno.h>
14#include <fcntl.h>
15#include <stdio.h>
16#include <stdlib.h>
17#include <syslog.h>
18#include <string.h>
19#include <unistd.h>
20#include <ctype.h>
21
Willy Tarreau45cb4fb2009-10-26 21:10:04 +010022#include <eb32tree.h>
Willy Tarreauabe45b62010-10-28 20:33:46 +020023#include <eb64tree.h>
24#include <ebistree.h>
Willy Tarreaud2201062010-05-27 18:17:30 +020025#include <ebsttree.h>
Willy Tarreau72c28532009-01-22 18:56:50 +010026
Willy Tarreaud2201062010-05-27 18:17:30 +020027#define SOURCE_FIELD 5
Willy Tarreau72c28532009-01-22 18:56:50 +010028#define ACCEPT_FIELD 6
Willy Tarreaud2201062010-05-27 18:17:30 +020029#define SERVER_FIELD 8
Willy Tarreau72c28532009-01-22 18:56:50 +010030#define TIME_FIELD 9
31#define STATUS_FIELD 10
Willy Tarreaud8fc1102010-09-12 17:56:16 +020032#define TERM_CODES_FIELD 14
Willy Tarreau72c28532009-01-22 18:56:50 +010033#define CONN_FIELD 15
Willy Tarreauabe45b62010-10-28 20:33:46 +020034#define METH_FIELD 17
35#define URL_FIELD 18
Willy Tarreau72c28532009-01-22 18:56:50 +010036#define MAXLINE 16384
37#define QBITS 4
38
39#define SKIP_CHAR(p,c) do { while (1) if (!*p) break; else if (*(p++) == c) break; } while (0)
40
41/* [0] = err/date, [1] = req, [2] = conn, [3] = resp, [4] = data */
42static struct eb_root timers[5] = {
43 EB_ROOT_UNIQUE, EB_ROOT_UNIQUE, EB_ROOT_UNIQUE,
44 EB_ROOT_UNIQUE, EB_ROOT_UNIQUE,
45};
46
47struct timer {
48 struct eb32_node node;
49 unsigned int count;
50};
51
Willy Tarreaud2201062010-05-27 18:17:30 +020052struct srv_st {
53 unsigned int st_cnt[6]; /* 0xx to 5xx */
54 unsigned int nb_ct, nb_rt, nb_ok;
55 unsigned long long cum_ct, cum_rt;
56 struct ebmb_node node;
57 /* don't put anything else here, the server name will be there */
58};
Willy Tarreau72c28532009-01-22 18:56:50 +010059
Willy Tarreauabe45b62010-10-28 20:33:46 +020060struct url_stat {
61 union {
62 struct ebpt_node url;
63 struct eb64_node val;
64 } node;
65 char *url;
66 unsigned long long total_time; /* sum(all reqs' times) */
67 unsigned long long total_time_ok; /* sum(all OK reqs' times) */
68 unsigned int nb_err, nb_req;
69};
70
Willy Tarreau72c28532009-01-22 18:56:50 +010071#define FILT_COUNT_ONLY 0x01
72#define FILT_INVERT 0x02
73#define FILT_QUIET 0x04
74#define FILT_ERRORS_ONLY 0x08
75#define FILT_ACC_DELAY 0x10
76#define FILT_ACC_COUNT 0x20
77#define FILT_GRAPH_TIMERS 0x40
Willy Tarreau214c2032009-02-20 11:02:32 +010078#define FILT_PERCENTILE 0x80
Willy Tarreau5bdfd962009-10-14 15:16:29 +020079#define FILT_TIME_RESP 0x100
80
81#define FILT_INVERT_ERRORS 0x200
82#define FILT_INVERT_TIME_RESP 0x400
Willy Tarreau72c28532009-01-22 18:56:50 +010083
Willy Tarreau0f423a72010-05-03 10:50:54 +020084#define FILT_COUNT_STATUS 0x800
Willy Tarreaud2201062010-05-27 18:17:30 +020085#define FILT_COUNT_SRV_STATUS 0x1000
Willy Tarreaud8fc1102010-09-12 17:56:16 +020086#define FILT_COUNT_TERM_CODES 0x2000
Willy Tarreau0f423a72010-05-03 10:50:54 +020087
Willy Tarreauabe45b62010-10-28 20:33:46 +020088#define FILT_COUNT_URL_ONLY 0x004000
89#define FILT_COUNT_URL_COUNT 0x008000
90#define FILT_COUNT_URL_ERR 0x010000
91#define FILT_COUNT_URL_TTOT 0x020000
92#define FILT_COUNT_URL_TAVG 0x040000
93#define FILT_COUNT_URL_TTOTO 0x080000
94#define FILT_COUNT_URL_TAVGO 0x100000
95#define FILT_COUNT_URL_ANY (FILT_COUNT_URL_ONLY|FILT_COUNT_URL_COUNT|FILT_COUNT_URL_ERR| \
96 FILT_COUNT_URL_TTOT|FILT_COUNT_URL_TAVG|FILT_COUNT_URL_TTOTO|FILT_COUNT_URL_TAVGO)
97
Willy Tarreau72c28532009-01-22 18:56:50 +010098unsigned int filter = 0;
99unsigned int filter_invert = 0;
Willy Tarreau214c2032009-02-20 11:02:32 +0100100const char *line;
Willy Tarreau72c28532009-01-22 18:56:50 +0100101
Willy Tarreau214c2032009-02-20 11:02:32 +0100102const char *fgets2(FILE *stream);
Willy Tarreau72c28532009-01-22 18:56:50 +0100103
104void die(const char *msg)
105{
106 fprintf(stderr,
107 "%s"
Willy Tarreauabe45b62010-10-28 20:33:46 +0200108 "Usage: halog [-q] [-c] [-v] {-gt|-pct|-st|-tc|-srv|-u|-uc|-ue|-ua|-ut|-uao|-uto}\n"
109 " [-s <skip>] [-e|-E] [-rt|-RT <time>] [-ad <delay>] [-ac <count>] < file.log\n"
Willy Tarreau72c28532009-01-22 18:56:50 +0100110 "\n",
111 msg ? msg : ""
112 );
113 exit(1);
114}
115
116
117/* return pointer to first char not part of current field starting at <p>. */
118const char *field_stop(const char *p)
119{
120 unsigned char c;
121
122 while (1) {
123 c = *(p++);
124 if (c > ' ')
125 continue;
126 if (c == ' ' || c == '\t' || c == 0)
127 break;
128 }
129 return p - 1;
130}
131
132/* return field <field> (starting from 1) in string <p>. Only consider
133 * contiguous spaces (or tabs) as one delimiter. May return pointer to
134 * last char if field is not found. Equivalent to awk '{print $field}'.
135 */
136const char *field_start(const char *p, int field)
137{
138 unsigned char c;
139 while (1) {
140 /* skip spaces */
141 while (1) {
142 c = *p;
143 if (c > ' ')
144 break;
145 if (c == ' ' || c == '\t')
146 goto next;
147 if (!c) /* end of line */
148 return p;
149 /* other char => new field */
150 break;
151 next:
152 p++;
153 }
154
155 /* start of field */
156 field--;
157 if (!field)
158 return p;
159
160 /* skip this field */
161 while (1) {
162 c = *(p++);
163 if (c > ' ')
164 continue;
165 if (c == ' ' || c == '\t')
166 break;
167 if (c == '\0')
168 return p;
169 }
170 }
171}
172
173/* keep only the <bits> higher bits of <i> */
174static inline unsigned int quantify_u32(unsigned int i, int bits)
175{
176 int high;
177
178 if (!bits)
179 return 0;
180
181 if (i)
182 high = fls_auto(i); // 1 to 32
183 else
184 high = 0;
185
186 if (high <= bits)
187 return i;
188
189 return i & ~((1 << (high - bits)) - 1);
190}
191
192/* keep only the <bits> higher bits of the absolute value of <i>, as well as
193 * its sign. */
194static inline int quantify(int i, int bits)
195{
196 if (i >= 0)
197 return quantify_u32(i, bits);
198 else
199 return -quantify_u32(-i, bits);
200}
201
202/* Insert timer value <v> into tree <r>. A pre-allocated node must be passed
203 * in <alloc>. It may be NULL, in which case the function will allocate it
204 * itself. It will be reset to NULL once consumed. The caller is responsible
205 * for freeing the node once not used anymore. The node where the value was
206 * inserted is returned.
207 */
208struct timer *insert_timer(struct eb_root *r, struct timer **alloc, int v)
209{
210 struct timer *t = *alloc;
211 struct eb32_node *n;
212
213 if (!t) {
214 t = calloc(sizeof(*t), 1);
215 if (unlikely(!t)) {
216 fprintf(stderr, "%s: not enough memory\n", __FUNCTION__);
217 exit(1);
218 }
219 }
220 t->node.key = quantify(v, QBITS); // keep only the higher QBITS bits
221
222 n = eb32i_insert(r, &t->node);
223 if (n == &t->node)
224 t = NULL; /* node inserted, will malloc next time */
225
226 *alloc = t;
227 return container_of(n, struct timer, node);
228}
229
230/* Insert value value <v> into tree <r>. A pre-allocated node must be passed
231 * in <alloc>. It may be NULL, in which case the function will allocate it
232 * itself. It will be reset to NULL once consumed. The caller is responsible
233 * for freeing the node once not used anymore. The node where the value was
234 * inserted is returned.
235 */
236struct timer *insert_value(struct eb_root *r, struct timer **alloc, int v)
237{
238 struct timer *t = *alloc;
239 struct eb32_node *n;
240
241 if (!t) {
242 t = calloc(sizeof(*t), 1);
243 if (unlikely(!t)) {
244 fprintf(stderr, "%s: not enough memory\n", __FUNCTION__);
245 exit(1);
246 }
247 }
248 t->node.key = v;
249
250 n = eb32i_insert(r, &t->node);
251 if (n == &t->node)
252 t = NULL; /* node inserted, will malloc next time */
253
254 *alloc = t;
255 return container_of(n, struct timer, node);
256}
257
258int str2ic(const char *s)
259{
260 int i = 0;
261 int j, k;
262
263 if (*s != '-') {
264 /* positive number */
265 while (1) {
266 j = (*s++) - '0';
267 k = i * 10;
268 if ((unsigned)j > 9)
269 break;
270 i = k + j;
271 }
272 } else {
273 /* negative number */
274 s++;
275 while (1) {
276 j = (*s++) - '0';
277 k = i * 10;
278 if ((unsigned)j > 9)
279 break;
280 i = k - j;
281 }
282 }
283
284 return i;
285}
286
287
288/* Equivalent to strtoul with a length. */
289static inline unsigned int __strl2ui(const char *s, int len)
290{
291 unsigned int i = 0;
292 while (len-- > 0) {
293 i = i * 10 - '0';
294 i += (unsigned char)*s++;
295 }
296 return i;
297}
298
299unsigned int strl2ui(const char *s, int len)
300{
301 return __strl2ui(s, len);
302}
303
304/* Convert "[04/Dec/2008:09:49:40.555]" to an integer equivalent to the time of
305 * the day in milliseconds. It returns -1 for all unparsable values. The parser
306 * looks ugly but gcc emits far better code that way.
307 */
308int convert_date(const char *field)
309{
310 unsigned int h, m, s, ms;
311 unsigned char c;
312 const char *b, *e;
313
314 h = m = s = ms = 0;
315 e = field;
316
317 /* skip the date */
318 while (1) {
319 c = *(e++);
320 if (c == ':')
321 break;
322 if (!c)
323 goto out_err;
324 }
325
326 /* hour + ':' */
327 b = e;
328 while (1) {
329 c = *(e++) - '0';
330 if (c > 9)
331 break;
332 h = h * 10 + c;
333 }
334 if (c == (unsigned char)(0 - '0'))
335 goto out_err;
336
337 /* minute + ':' */
338 b = e;
339 while (1) {
340 c = *(e++) - '0';
341 if (c > 9)
342 break;
343 m = m * 10 + c;
344 }
345 if (c == (unsigned char)(0 - '0'))
346 goto out_err;
347
348 /* second + '.' or ']' */
349 b = e;
350 while (1) {
351 c = *(e++) - '0';
352 if (c > 9)
353 break;
354 s = s * 10 + c;
355 }
356 if (c == (unsigned char)(0 - '0'))
357 goto out_err;
358
359 /* if there's a '.', we have milliseconds */
360 if (c == (unsigned char)('.' - '0')) {
361 /* millisecond second + ']' */
362 b = e;
363 while (1) {
364 c = *(e++) - '0';
365 if (c > 9)
366 break;
367 ms = ms * 10 + c;
368 }
369 if (c == (unsigned char)(0 - '0'))
370 goto out_err;
371 }
372 return (((h * 60) + m) * 60 + s) * 1000 + ms;
373 out_err:
374 return -1;
375}
376
377void truncated_line(int linenum, const char *line)
378{
379 if (!(filter & FILT_QUIET))
380 fprintf(stderr, "Truncated line %d: %s\n", linenum, line);
381}
382
383int main(int argc, char **argv)
384{
385 const char *b, *e, *p;
386 const char *output_file = NULL;
387 int f, tot, last, linenum, err, parse_err;
388 struct timer *t = NULL, *t2;
389 struct eb32_node *n;
Willy Tarreauabe45b62010-10-28 20:33:46 +0200390 struct url_stat *ustat = NULL;
391 struct ebpt_node *ebpt_old;
Willy Tarreau72c28532009-01-22 18:56:50 +0100392 int val, test;
393 int array[5];
394 int filter_acc_delay = 0, filter_acc_count = 0;
Willy Tarreau5bdfd962009-10-14 15:16:29 +0200395 int filter_time_resp = 0;
Willy Tarreau72c28532009-01-22 18:56:50 +0100396 int skip_fields = 1;
397
398 argc--; argv++;
399 while (argc > 0) {
400 if (*argv[0] != '-')
401 break;
402
403 if (strcmp(argv[0], "-ad") == 0) {
404 if (argc < 2) die("missing option for -ad");
405 argc--; argv++;
406 filter |= FILT_ACC_DELAY;
407 filter_acc_delay = atol(*argv);
408 }
409 else if (strcmp(argv[0], "-ac") == 0) {
410 if (argc < 2) die("missing option for -ac");
411 argc--; argv++;
412 filter |= FILT_ACC_COUNT;
413 filter_acc_count = atol(*argv);
414 }
Willy Tarreau5bdfd962009-10-14 15:16:29 +0200415 else if (strcmp(argv[0], "-rt") == 0) {
416 if (argc < 2) die("missing option for -rt");
417 argc--; argv++;
418 filter |= FILT_TIME_RESP;
419 filter_time_resp = atol(*argv);
420 }
421 else if (strcmp(argv[0], "-RT") == 0) {
422 if (argc < 2) die("missing option for -RT");
423 argc--; argv++;
424 filter |= FILT_TIME_RESP | FILT_INVERT_TIME_RESP;
425 filter_time_resp = atol(*argv);
426 }
Willy Tarreau72c28532009-01-22 18:56:50 +0100427 else if (strcmp(argv[0], "-s") == 0) {
428 if (argc < 2) die("missing option for -s");
429 argc--; argv++;
430 skip_fields = atol(*argv);
431 }
432 else if (strcmp(argv[0], "-e") == 0)
433 filter |= FILT_ERRORS_ONLY;
Willy Tarreau5bdfd962009-10-14 15:16:29 +0200434 else if (strcmp(argv[0], "-E") == 0)
435 filter |= FILT_ERRORS_ONLY | FILT_INVERT_ERRORS;
Willy Tarreau72c28532009-01-22 18:56:50 +0100436 else if (strcmp(argv[0], "-c") == 0)
437 filter |= FILT_COUNT_ONLY;
438 else if (strcmp(argv[0], "-q") == 0)
439 filter |= FILT_QUIET;
440 else if (strcmp(argv[0], "-v") == 0)
441 filter_invert = !filter_invert;
442 else if (strcmp(argv[0], "-gt") == 0)
443 filter |= FILT_GRAPH_TIMERS;
Willy Tarreau214c2032009-02-20 11:02:32 +0100444 else if (strcmp(argv[0], "-pct") == 0)
445 filter |= FILT_PERCENTILE;
Willy Tarreau0f423a72010-05-03 10:50:54 +0200446 else if (strcmp(argv[0], "-st") == 0)
447 filter |= FILT_COUNT_STATUS;
Willy Tarreaud2201062010-05-27 18:17:30 +0200448 else if (strcmp(argv[0], "-srv") == 0)
449 filter |= FILT_COUNT_SRV_STATUS;
Willy Tarreaud8fc1102010-09-12 17:56:16 +0200450 else if (strcmp(argv[0], "-tc") == 0)
451 filter |= FILT_COUNT_TERM_CODES;
Willy Tarreauabe45b62010-10-28 20:33:46 +0200452 else if (strcmp(argv[0], "-u") == 0)
453 filter |= FILT_COUNT_URL_ONLY;
454 else if (strcmp(argv[0], "-uc") == 0)
455 filter |= FILT_COUNT_URL_COUNT;
456 else if (strcmp(argv[0], "-ue") == 0)
457 filter |= FILT_COUNT_URL_ERR;
458 else if (strcmp(argv[0], "-ua") == 0)
459 filter |= FILT_COUNT_URL_TAVG;
460 else if (strcmp(argv[0], "-ut") == 0)
461 filter |= FILT_COUNT_URL_TTOT;
462 else if (strcmp(argv[0], "-uao") == 0)
463 filter |= FILT_COUNT_URL_TAVGO;
464 else if (strcmp(argv[0], "-uto") == 0)
465 filter |= FILT_COUNT_URL_TTOTO;
Willy Tarreau72c28532009-01-22 18:56:50 +0100466 else if (strcmp(argv[0], "-o") == 0) {
467 if (output_file)
468 die("Fatal: output file name already specified.\n");
469 if (argc < 2)
470 die("Fatal: missing output file name.\n");
471 output_file = argv[1];
472 }
473 argc--;
474 argv++;
475 }
476
477 if (!filter)
478 die("No action specified.\n");
479
480 if (filter & FILT_ACC_COUNT && !filter_acc_count)
481 filter_acc_count=1;
482
483 if (filter & FILT_ACC_DELAY && !filter_acc_delay)
484 filter_acc_delay = 1;
485
486 linenum = 0;
487 tot = 0;
488 parse_err = 0;
489
Willy Tarreau214c2032009-02-20 11:02:32 +0100490 while ((line = fgets2(stdin)) != NULL) {
Willy Tarreau72c28532009-01-22 18:56:50 +0100491 linenum++;
492
Willy Tarreau5bdfd962009-10-14 15:16:29 +0200493 test = 1;
Willy Tarreau2651ac32010-05-05 12:20:19 +0200494 if (unlikely(filter & FILT_TIME_RESP)) {
Willy Tarreau5bdfd962009-10-14 15:16:29 +0200495 int tps;
496
497 /* only report lines with response times larger than filter_time_resp */
498 b = field_start(line, TIME_FIELD + skip_fields);
499 if (!*b) {
500 truncated_line(linenum, line);
501 continue;
502 }
503
504 e = field_stop(b + 1);
Willy Tarreau24bcb4f2010-10-28 20:39:50 +0200505 /* we have field TIME_FIELD in [b]..[e-1], let's check only the response time */
Willy Tarreau5bdfd962009-10-14 15:16:29 +0200506
507 p = b;
508 err = 0;
Willy Tarreau24bcb4f2010-10-28 20:39:50 +0200509 f = 0;
510 while (*p) {
Willy Tarreau5bdfd962009-10-14 15:16:29 +0200511 tps = str2ic(p);
512 if (tps < 0) {
513 tps = -1;
514 err = 1;
515 }
Willy Tarreau24bcb4f2010-10-28 20:39:50 +0200516 if (++f == 4)
517 break;
Willy Tarreau5bdfd962009-10-14 15:16:29 +0200518 SKIP_CHAR(p, '/');
519 }
520
521 if (f < 4) {
522 parse_err++;
523 continue;
524 }
525
526 test &= (tps >= filter_time_resp) ^ !!(filter & FILT_INVERT_TIME_RESP);
527 }
528
Willy Tarreau2651ac32010-05-05 12:20:19 +0200529 if (unlikely(filter & FILT_ERRORS_ONLY)) {
Willy Tarreau72c28532009-01-22 18:56:50 +0100530 /* only report erroneous status codes */
531 b = field_start(line, STATUS_FIELD + skip_fields);
532 if (!*b) {
533 truncated_line(linenum, line);
534 continue;
535 }
536 if (*b == '-') {
Willy Tarreau5bdfd962009-10-14 15:16:29 +0200537 test &= !!(filter & FILT_INVERT_ERRORS);
Willy Tarreau72c28532009-01-22 18:56:50 +0100538 } else {
539 val = strl2ui(b, 3);
Willy Tarreau5bdfd962009-10-14 15:16:29 +0200540 test &= (val >= 500 && val <= 599) ^ !!(filter & FILT_INVERT_ERRORS);
Willy Tarreau72c28532009-01-22 18:56:50 +0100541 }
Willy Tarreau72c28532009-01-22 18:56:50 +0100542 }
543
Willy Tarreau0f423a72010-05-03 10:50:54 +0200544 test ^= filter_invert;
545 if (!test)
546 continue;
547
Willy Tarreau2651ac32010-05-05 12:20:19 +0200548 if (unlikely(filter & (FILT_ACC_COUNT|FILT_ACC_DELAY))) {
Willy Tarreau72c28532009-01-22 18:56:50 +0100549 b = field_start(line, ACCEPT_FIELD + skip_fields);
550 if (!*b) {
551 truncated_line(linenum, line);
552 continue;
553 }
554
Willy Tarreau214c2032009-02-20 11:02:32 +0100555 tot++;
Willy Tarreau72c28532009-01-22 18:56:50 +0100556 val = convert_date(b);
557 //printf("date=%s => %d\n", b, val);
558 if (val < 0) {
559 parse_err++;
560 continue;
561 }
562
563 t2 = insert_value(&timers[0], &t, val);
564 t2->count++;
565 continue;
566 }
567
Willy Tarreau2651ac32010-05-05 12:20:19 +0200568 if (unlikely(filter & (FILT_GRAPH_TIMERS|FILT_PERCENTILE))) {
Willy Tarreau72c28532009-01-22 18:56:50 +0100569 int f;
570
571 b = field_start(line, TIME_FIELD + skip_fields);
572 if (!*b) {
573 truncated_line(linenum, line);
574 continue;
575 }
576
577 e = field_stop(b + 1);
578 /* we have field TIME_FIELD in [b]..[e-1] */
579
580 p = b;
581 err = 0;
Willy Tarreau24bcb4f2010-10-28 20:39:50 +0200582 f = 0;
583 while (*p) {
Willy Tarreau72c28532009-01-22 18:56:50 +0100584 array[f] = str2ic(p);
585 if (array[f] < 0) {
586 array[f] = -1;
587 err = 1;
588 }
Willy Tarreau24bcb4f2010-10-28 20:39:50 +0200589 if (++f == 5)
590 break;
Willy Tarreau72c28532009-01-22 18:56:50 +0100591 SKIP_CHAR(p, '/');
592 }
593
594 if (f < 5) {
595 parse_err++;
596 continue;
597 }
598
599 /* if we find at least one negative time, we count one error
600 * with a time equal to the total session time. This will
601 * emphasize quantum timing effects associated to known
602 * timeouts. Note that on some buggy machines, it is possible
603 * that the total time is negative, hence the reason to reset
604 * it.
605 */
Willy Tarreau214c2032009-02-20 11:02:32 +0100606
607 if (filter & FILT_GRAPH_TIMERS) {
608 if (err) {
609 if (array[4] < 0)
610 array[4] = -1;
611 t2 = insert_timer(&timers[0], &t, array[4]); // total time
612 t2->count++;
613 } else {
614 int v;
Willy Tarreau72c28532009-01-22 18:56:50 +0100615
Willy Tarreau214c2032009-02-20 11:02:32 +0100616 t2 = insert_timer(&timers[1], &t, array[0]); t2->count++; // req
617 t2 = insert_timer(&timers[2], &t, array[2]); t2->count++; // conn
618 t2 = insert_timer(&timers[3], &t, array[3]); t2->count++; // resp
619
620 v = array[4] - array[0] - array[1] - array[2] - array[3]; // data time
621 if (v < 0 && !(filter & FILT_QUIET))
622 fprintf(stderr, "ERR: %s (%d %d %d %d %d => %d)\n",
623 line, array[0], array[1], array[2], array[3], array[4], v);
624 t2 = insert_timer(&timers[4], &t, v); t2->count++;
625 tot++;
626 }
627 } else { /* percentile */
628 if (err) {
629 if (array[4] < 0)
630 array[4] = -1;
631 t2 = insert_value(&timers[0], &t, array[4]); // total time
632 t2->count++;
633 } else {
634 int v;
Willy Tarreau72c28532009-01-22 18:56:50 +0100635
Willy Tarreau214c2032009-02-20 11:02:32 +0100636 t2 = insert_value(&timers[1], &t, array[0]); t2->count++; // req
637 t2 = insert_value(&timers[2], &t, array[2]); t2->count++; // conn
638 t2 = insert_value(&timers[3], &t, array[3]); t2->count++; // resp
639
640 v = array[4] - array[0] - array[1] - array[2] - array[3]; // data time
641 if (v < 0 && !(filter & FILT_QUIET))
642 fprintf(stderr, "ERR: %s (%d %d %d %d %d => %d)\n",
643 line, array[0], array[1], array[2], array[3], array[4], v);
644 t2 = insert_value(&timers[4], &t, v); t2->count++;
645 tot++;
646 }
Willy Tarreau72c28532009-01-22 18:56:50 +0100647 }
648 continue;
649 }
650
Willy Tarreau2651ac32010-05-05 12:20:19 +0200651 if (unlikely(filter & FILT_COUNT_STATUS)) {
Willy Tarreau54170812010-09-13 22:50:49 +0200652 /* first, let's ensure that the line is a traffic line (beginning
653 * with an IP address)
654 */
655 b = field_start(line, SOURCE_FIELD + skip_fields);
656 if (*b < '0' || *b > '9') {
657 parse_err++;
658 continue;
659 }
660
661 b = field_start(b, STATUS_FIELD - SOURCE_FIELD + 1);
Willy Tarreau0f423a72010-05-03 10:50:54 +0200662 if (!*b) {
663 truncated_line(linenum, line);
664 continue;
665 }
666 val = str2ic(b);
667
668 t2 = insert_value(&timers[0], &t, val);
669 t2->count++;
Willy Tarreau5bdfd962009-10-14 15:16:29 +0200670 continue;
Willy Tarreau0f423a72010-05-03 10:50:54 +0200671 }
Willy Tarreau5bdfd962009-10-14 15:16:29 +0200672
Willy Tarreaud8fc1102010-09-12 17:56:16 +0200673 if (unlikely(filter & FILT_COUNT_TERM_CODES)) {
Willy Tarreau54170812010-09-13 22:50:49 +0200674 /* first, let's ensure that the line is a traffic line (beginning
675 * with an IP address)
676 */
677 b = field_start(line, SOURCE_FIELD + skip_fields);
678 if (*b < '0' || *b > '9') {
679 parse_err++;
680 continue;
681 }
682
683 b = field_start(b, TERM_CODES_FIELD - SOURCE_FIELD + 1);
Willy Tarreaud8fc1102010-09-12 17:56:16 +0200684 if (!*b) {
685 truncated_line(linenum, line);
686 continue;
687 }
688 val = 256 * b[0] + b[1];
689
690 t2 = insert_value(&timers[0], &t, val);
691 t2->count++;
692 continue;
693 }
694
Willy Tarreaud2201062010-05-27 18:17:30 +0200695 if (unlikely(filter & FILT_COUNT_SRV_STATUS)) {
696 char *srv_name;
697 struct ebmb_node *srv_node;
698 struct srv_st *srv;
699
700 /* first, let's ensure that the line is a traffic line (beginning
701 * with an IP address)
702 */
703 b = field_start(line, SOURCE_FIELD + skip_fields);
704 if (*b < '0' || *b > '9') {
705 parse_err++;
706 continue;
707 }
708
709 /* the server field is before the status field, so let's
710 * parse them in the proper order.
711 */
712 b = field_start(b, SERVER_FIELD - SOURCE_FIELD + 1);
713 if (!*b) {
714 truncated_line(linenum, line);
715 continue;
716 }
717
718 e = field_stop(b + 1); /* we have the server name in [b]..[e-1] */
719
720 /* the chance that a server name already exists is extremely high,
721 * so let's perform a normal lookup first.
722 */
723 srv_node = ebst_lookup_len(&timers[0], b, e - b);
724 srv = container_of(srv_node, struct srv_st, node);
725
726 if (!srv_node) {
727 /* server not yet in the tree, let's create it */
728 srv = (void *)calloc(1, sizeof(struct srv_st) + e - b + 1);
729 srv_node = &srv->node;
730 memcpy(&srv_node->key, b, e - b);
731 srv_node->key[e - b] = '\0';
732 ebst_insert(&timers[0], srv_node);
733 }
734
735 /* let's collect the connect and response times */
736 b = field_start(e, TIME_FIELD - SERVER_FIELD);
737 if (!*b) {
738 truncated_line(linenum, line);
739 continue;
740 }
741
742 e = field_stop(b + 1);
743 /* we have field TIME_FIELD in [b]..[e-1] */
744
745 p = b;
746 err = 0;
Willy Tarreau24bcb4f2010-10-28 20:39:50 +0200747 f = 0;
748 while (*p) {
Willy Tarreaud2201062010-05-27 18:17:30 +0200749 array[f] = str2ic(p);
750 if (array[f] < 0) {
751 array[f] = -1;
752 err = 1;
753 }
Willy Tarreau24bcb4f2010-10-28 20:39:50 +0200754 if (++f == 5)
755 break;
Willy Tarreaud2201062010-05-27 18:17:30 +0200756 SKIP_CHAR(p, '/');
757 }
758
759 if (f < 5) {
760 parse_err++;
761 continue;
762 }
763
764 /* OK we have our timers in array[2,3] */
765 if (!err)
766 srv->nb_ok++;
767
768 if (array[2] >= 0) {
769 srv->cum_ct += array[2];
770 srv->nb_ct++;
771 }
772
773 if (array[3] >= 0) {
774 srv->cum_rt += array[3];
775 srv->nb_rt++;
776 }
777
778 /* we're interested in the 5 HTTP status classes (1xx ... 5xx), and
779 * the invalid ones which will be reported as 0.
780 */
781 b = field_start(e, STATUS_FIELD - TIME_FIELD);
782 if (!*b) {
783 truncated_line(linenum, line);
784 continue;
785 }
786
787 val = 0;
788 if (*b >= '1' && *b <= '5')
789 val = *b - '0';
790
791 srv->st_cnt[val]++;
792 continue;
793 }
794
Willy Tarreauabe45b62010-10-28 20:33:46 +0200795 if (unlikely(filter & FILT_COUNT_URL_ANY)) {
796 /* first, let's ensure that the line is a traffic line (beginning
797 * with an IP address)
798 */
799 b = field_start(line, SOURCE_FIELD + skip_fields); // avg 95 ns per line
800 if (*b < '0' || *b > '9') {
801 parse_err++;
802 continue;
803 }
804
805 /* let's collect the response time */
806 b = field_start(field_stop(b + 1), TIME_FIELD - SOURCE_FIELD); // avg 115 ns per line
807 if (!*b) {
808 truncated_line(linenum, line);
809 continue;
810 }
811
812 /* we have the field TIME_FIELD starting at <b>. We'll
813 * parse the 5 timers to detect errors, it takes avg 55 ns per line.
814 */
815 e = b; err = 0; f = 0;
816 while (*e) {
817 array[f] = str2ic(e);
818 if (array[f] < 0) {
819 array[f] = -1;
820 err = 1;
821 }
822 if (++f == 5)
823 break;
824 SKIP_CHAR(e, '/');
825 }
826 if (f < 5) {
827 parse_err++;
828 continue;
829 }
830
831 /* OK we have our timers in array[3], and err is >0 if at
832 * least one -1 was seen. <e> points to the first char of
833 * the last timer. Let's prepare a new node with that.
834 */
835 if (unlikely(!ustat))
836 ustat = calloc(1, sizeof(*ustat));
837
838 ustat->nb_err = err;
839 ustat->nb_req = 1;
840
841 /* use array[4] = total time in case of error */
842 ustat->total_time = (array[3] >= 0) ? array[3] : array[4];
843 ustat->total_time_ok = (array[3] >= 0) ? array[3] : 0;
844
845 /* the line may be truncated because of a bad request or anything like this,
846 * without a method. Also, if it does not begin with an quote, let's skip to
847 * the next field because it's a capture. Let's fall back to the "method" itself
848 * if there's nothing else.
849 */
850 e = field_start(e, METH_FIELD - TIME_FIELD + 1); // avg 100 ns per line
851 while (*e != '"' && *e)
852 e = field_start(e, 2);
853
854 if (!*e) {
855 truncated_line(linenum, line);
856 continue;
857 }
858
859 b = field_start(e, URL_FIELD - METH_FIELD + 1); // avg 40 ns per line
860 if (!*b)
861 b = e;
862
863 /* stop at end of field or first ';' or '?', takes avg 64 ns per line */
864 e = b;
865 do {
866 if (*e == ' ' || *e == '?' || *e == ';' || *e == '\t') {
867 *(char *)e = 0;
868 break;
869 }
870 e++;
871 } while (*e);
872
873 /* now instead of copying the URL for a simple lookup, we'll link
874 * to it from the node we're trying to insert. If it returns a
875 * different value, it was already there. Otherwise we just have
876 * to dynamically realloc an entry using strdup().
877 */
878 ustat->node.url.key = (char *)b;
879 ebpt_old = ebis_insert(&timers[0], &ustat->node.url);
880
881 if (ebpt_old != &ustat->node.url) {
882 struct url_stat *ustat_old;
883 /* node was already there, let's update previous one */
884 ustat_old = container_of(ebpt_old, struct url_stat, node.url);
885 ustat_old->nb_req ++;
886 ustat_old->nb_err += ustat->nb_err;
887 ustat_old->total_time += ustat->total_time;
888 ustat_old->total_time_ok += ustat->total_time_ok;
889 } else {
890 ustat->url = ustat->node.url.key = strdup(ustat->node.url.key);
891 ustat = NULL; /* node was used */
892 }
893
894 continue;
895 }
896
Willy Tarreau72c28532009-01-22 18:56:50 +0100897 /* all other cases mean we just want to count lines */
898 tot++;
Willy Tarreau2651ac32010-05-05 12:20:19 +0200899 if (unlikely(!(filter & FILT_COUNT_ONLY)))
Willy Tarreau5bdfd962009-10-14 15:16:29 +0200900 puts(line);
Willy Tarreau72c28532009-01-22 18:56:50 +0100901 }
902
903 if (t)
904 free(t);
905
906 if (filter & FILT_COUNT_ONLY) {
907 printf("%d\n", tot);
908 exit(0);
909 }
910
Willy Tarreau72c28532009-01-22 18:56:50 +0100911 if (filter & (FILT_ACC_COUNT|FILT_ACC_DELAY)) {
912 /* sort and count all timers. Output will look like this :
913 * <accept_date> <delta_ms from previous one> <nb entries>
914 */
915 n = eb32_first(&timers[0]);
916
917 if (n)
918 last = n->key;
919 while (n) {
920 unsigned int d, h, m, s, ms;
921
922 t = container_of(n, struct timer, node);
923 h = n->key;
924 d = h - last;
925 last = h;
926
927 if (d >= filter_acc_delay && t->count >= filter_acc_count) {
928 ms = h % 1000; h = h / 1000;
929 s = h % 60; h = h / 60;
930 m = h % 60; h = h / 60;
931 tot++;
932 printf("%02d:%02d:%02d.%03d %d %d %d\n", h, m, s, ms, last, d, t->count);
933 }
934 n = eb32_next(n);
935 }
936 }
937 else if (filter & FILT_GRAPH_TIMERS) {
938 /* sort all timers */
939 for (f = 0; f < 5; f++) {
940 struct eb32_node *n;
941 int val;
942
943 val = 0;
944 n = eb32_first(&timers[f]);
945 while (n) {
946 int i;
947 double d;
948
949 t = container_of(n, struct timer, node);
950 last = n->key;
951 val = t->count;
952
953 i = (last < 0) ? -last : last;
954 i = fls_auto(i) - QBITS;
955
956 if (i > 0)
957 d = val / (double)(1 << i);
958 else
959 d = val;
960
961 if (d > 0.0) {
962 printf("%d %d %f\n", f, last, d+1.0);
963 tot++;
964 }
965
966 n = eb32_next(n);
967 }
Willy Tarreau214c2032009-02-20 11:02:32 +0100968 }
969 }
970 else if (filter & FILT_PERCENTILE) {
971 /* report timers by percentile :
972 * <percent> <total> <max_req_time> <max_conn_time> <max_resp_time> <max_data_time>
973 * We don't count errs.
974 */
975 struct eb32_node *n[5];
976 unsigned long cum[5];
977 double step;
978
Willy Tarreau910ba4b2009-11-17 10:16:19 +0100979 if (!tot)
980 goto empty;
981
Willy Tarreau214c2032009-02-20 11:02:32 +0100982 for (f = 1; f < 5; f++) {
983 n[f] = eb32_first(&timers[f]);
984 cum[f] = container_of(n[f], struct timer, node)->count;
985 }
986
987 for (step = 1; step <= 1000;) {
988 unsigned int thres = tot * (step / 1000.0);
989
990 printf("%3.1f %d ", step/10.0, thres);
991 for (f = 1; f < 5; f++) {
992 struct eb32_node *next;
993 while (cum[f] < thres) {
994 /* need to find other keys */
995 next = eb32_next(n[f]);
996 if (!next)
997 break;
998 n[f] = next;
999 cum[f] += container_of(next, struct timer, node)->count;
1000 }
1001
1002 /* value still within $step % of total */
1003 printf("%d ", n[f]->key);
1004 }
1005 putchar('\n');
1006 if (step >= 100 && step < 900)
1007 step += 50; // jump 5% by 5% between those steps.
1008 else if (step >= 20 && step < 980)
1009 step += 10;
1010 else
1011 step += 1;
Willy Tarreau72c28532009-01-22 18:56:50 +01001012 }
1013 }
Willy Tarreau0f423a72010-05-03 10:50:54 +02001014 else if (filter & FILT_COUNT_STATUS) {
1015 /* output all statuses in the form of <status> <occurrences> */
1016 n = eb32_first(&timers[0]);
1017 while (n) {
1018 t = container_of(n, struct timer, node);
1019 printf("%d %d\n", n->key, t->count);
1020 n = eb32_next(n);
1021 }
1022 }
Willy Tarreaud2201062010-05-27 18:17:30 +02001023 else if (unlikely(filter & FILT_COUNT_SRV_STATUS)) {
1024 char *srv_name;
1025 struct ebmb_node *srv_node;
1026 struct srv_st *srv;
1027
1028 printf("#srv_name 1xx 2xx 3xx 4xx 5xx other tot_req req_ok pct_ok avg_ct avg_rt\n");
1029
1030 srv_node = ebmb_first(&timers[0]);
1031 while (srv_node) {
1032 int tot_rq;
1033
1034 srv = container_of(srv_node, struct srv_st, node);
1035
1036 tot_rq = 0;
1037 for (f = 0; f <= 5; f++)
1038 tot_rq += srv->st_cnt[f];
1039
1040 printf("%s %d %d %d %d %d %d %d %d %.1f %d %d\n",
1041 srv_node->key, srv->st_cnt[1], srv->st_cnt[2],
1042 srv->st_cnt[3], srv->st_cnt[4], srv->st_cnt[5], srv->st_cnt[0],
1043 tot_rq,
1044 srv->nb_ok, (double)srv->nb_ok * 100.0 / (tot_rq?tot_rq:1),
1045 (int)(srv->cum_ct / (srv->nb_ct?srv->nb_ct:1)), (int)(srv->cum_rt / (srv->nb_rt?srv->nb_rt:1)));
1046 srv_node = ebmb_next(srv_node);
1047 tot++;
1048 }
1049 }
Willy Tarreaud8fc1102010-09-12 17:56:16 +02001050 else if (filter & FILT_COUNT_TERM_CODES) {
1051 /* output all statuses in the form of <code> <occurrences> */
1052 n = eb32_first(&timers[0]);
1053 while (n) {
1054 t = container_of(n, struct timer, node);
1055 printf("%c%c %d\n", (n->key >> 8), (n->key) & 255, t->count);
1056 n = eb32_next(n);
1057 }
1058 }
Willy Tarreauabe45b62010-10-28 20:33:46 +02001059 else if (unlikely(filter & FILT_COUNT_URL_ANY)) {
1060 char *srv_name;
1061 struct eb_node *node, *next;
1062
1063 if (!(filter & FILT_COUNT_URL_ONLY)) {
1064 /* we have to sort on another criterion. We'll use timers[1] for the
1065 * destination tree.
1066 */
1067
1068 timers[1] = EB_ROOT; /* reconfigure to accept duplicates */
1069 for (node = eb_first(&timers[0]); node; node = next) {
1070 next = eb_next(node);
1071 eb_delete(node);
1072
1073 ustat = container_of(node, struct url_stat, node.url.node);
1074
1075 if (filter & FILT_COUNT_URL_COUNT)
1076 ustat->node.val.key = ustat->nb_req;
1077 else if (filter & FILT_COUNT_URL_ERR)
1078 ustat->node.val.key = ustat->nb_err;
1079 else if (filter & FILT_COUNT_URL_TTOT)
1080 ustat->node.val.key = ustat->total_time;
1081 else if (filter & FILT_COUNT_URL_TAVG)
1082 ustat->node.val.key = ustat->nb_req ? ustat->total_time / ustat->nb_req : 0;
1083 else if (filter & FILT_COUNT_URL_TTOTO)
1084 ustat->node.val.key = ustat->total_time_ok;
1085 else if (filter & FILT_COUNT_URL_TAVGO)
1086 ustat->node.val.key = (ustat->nb_req - ustat->nb_err) ? ustat->total_time_ok / (ustat->nb_req - ustat->nb_err) : 0;
1087 else
1088 ustat->node.val.key = 0;
1089
1090 eb64_insert(&timers[1], &ustat->node.val);
1091 }
1092 /* switch trees */
1093 timers[0] = timers[1];
1094 }
1095
1096 printf("#req err ttot tavg oktot okavg url\n");
1097
1098 /* scan the tree in its reverse sorting order */
1099 node = eb_last(&timers[0]);
1100 while (node) {
1101 ustat = container_of(node, struct url_stat, node.url.node);
1102 printf("%d %d %Ld %Ld %Ld %Ld %s\n",
1103 ustat->nb_req,
1104 ustat->nb_err,
1105 ustat->total_time,
1106 ustat->nb_req ? ustat->total_time / ustat->nb_req : 0,
1107 ustat->total_time_ok,
1108 (ustat->nb_req - ustat->nb_err) ? ustat->total_time_ok / (ustat->nb_req - ustat->nb_err) : 0,
1109 ustat->url);
1110
1111 node = eb_prev(node);
1112 tot++;
1113 }
1114 }
Willy Tarreaud2201062010-05-27 18:17:30 +02001115
Willy Tarreau910ba4b2009-11-17 10:16:19 +01001116 empty:
Willy Tarreau72c28532009-01-22 18:56:50 +01001117 if (!(filter & FILT_QUIET))
1118 fprintf(stderr, "%d lines in, %d lines out, %d parsing errors\n",
1119 linenum, tot, parse_err);
1120 exit(0);
1121}
1122
1123/*
1124 * Local variables:
1125 * c-indent-level: 8
1126 * c-basic-offset: 8
1127 * End:
1128 */