data/src/logger.c

   1 /*
   2   Copyright (C) 2010 Proxmox Server Solutions GmbH
   3
   4   This program is free software: you can redistribute it and/or modify
   5   it under the terms of the GNU Affero General Public License as published by
   6   the Free Software Foundation, either version 3 of the License, or
   7   (at your option) any later version.
   8
   9   This program is distributed in the hope that it will be useful,
  10   but WITHOUT ANY WARRANTY; without even the implied warranty of
  11   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  12   GNU Affero General Public License for more details.
  13
  14   You should have received a copy of the GNU Affero General Public License
  15   along with this program.  If not, see <http://www.gnu.org/licenses/>.
  16
  17   Author: Dietmar Maurer <dietmar@proxmox.com>
  18
  19 */
  20
  21 #ifdef HAVE_CONFIG_H
  22 #include <config.h>
  23 #endif /* HAVE_CONFIG_H */
  24
  25 #define _XOPEN_SOURCE /* glibc2 needs this */
  26 #include <time.h> /* for strptime */
  27
  28 #include <unistd.h>
  29 #include <stdio.h>
  30 #include <inttypes.h>
  31 #include <stdint.h>
  32 #include <glib.h>
  33 #include <string.h>
  34 #include <ctype.h>
  35 #include <sys/types.h>
  36 #include <sys/stat.h>
  37 #include <fcntl.h>
  38
  39
  40 #define SYSLOG_MAX_LINE_LENGTH 8192
  41
  42 #include "cfs-utils.h"
  43 #include "logger.h"
  44
  45 /*
  46  * 64 bit FNV-1a non-zero initial basis
  47  */
  48 #define FNV1A_64_INIT ((uint64_t) 0xcbf29ce484222325ULL)
  49 /*
  50  * 64 bit Fowler/Noll/Vo FNV-1a hash code
  51  * (copied from sheepdog sources)
  52  */
  53 static inline uint64_t fnv_64a_buf(const void *buf, size_t len, uint64_t hval)
  54 {
  55         unsigned char *bp = (unsigned char *) buf;
  56         unsigned char *be = bp + len;
  57         while (bp < be) {
  58                 hval ^= (uint64_t) *bp++;
  59                 hval += (hval << 1) + (hval << 4) + (hval << 5) +
  60                         (hval << 7) + (hval << 8) + (hval << 40);
  61         }
  62         return hval;
  63 }
  64
  65 static uint32_t uid_counter = 0;
  66
  67 struct clog_base {
  68         uint32_t size;
  69         uint32_t cpos;
  70         char data[];
  71 };
  72
  73 typedef struct {
  74         uint64_t node_digest;
  75         uint32_t uid;
  76         uint32_t time;
  77 } dedup_entry_t;
  78
  79 static clog_entry_t *
  80 clog_alloc_entry(
  81         clog_base_t *clog,
  82         uint32_t size)
  83 {
  84         g_return_val_if_fail(clog != NULL, NULL);
  85         g_return_val_if_fail(size > sizeof(clog_entry_t), NULL);
  86         g_return_val_if_fail(size <= CLOG_MAX_ENTRY_SIZE, NULL);
  87
  88         uint32_t realsize = ((size + 7) & 0xfffffff8);
  89
  90         uint32_t newpos;
  91
  92         if (!clog->cpos) {
  93                 newpos = sizeof(clog_base_t);
  94         } else {
  95                 clog_entry_t *cur = (clog_entry_t *)((char *)clog + clog->cpos);
  96                 newpos = cur->next;
  97                 if ((newpos + realsize) >= clog->size) {
  98                         newpos = sizeof(clog_base_t);
  99                 }
 100         }
 101
 102         clog_entry_t *entry = (clog_entry_t *)((char *)clog + newpos);
 103
 104         entry->prev = clog->cpos;
 105         clog->cpos = newpos;
 106         entry->next = newpos + realsize;
 107
 108         return entry;
 109 }
 110
 111 static void
 112 clog_dump_entry(clog_entry_t *cur, uint32_t cpos)
 113 {
 114         g_return_if_fail(cur != NULL);
 115
 116         char *node = cur->data;
 117         char *ident = node + cur->node_len;
 118         char *tag = ident + cur->ident_len;
 119         char *msg = tag + cur->tag_len;
 120
 121         time_t lt = cur->time;
 122         char tbuf[256];
 123         strftime(tbuf, sizeof(tbuf), "%F %T", localtime(&lt));
 124         printf("cpos %05d %08x %s", cpos, cur->uid, tbuf);
 125         printf(" %s{%016" PRIX64 "} %s[%s{%016" PRIX64 "}]: %s\n", node, cur->node_digest, tag, ident, cur->ident_digest, msg);
 126
 127 }
 128
 129 void
 130 clog_dump(clog_base_t *clog)
 131 {
 132         g_return_if_fail(clog != NULL);
 133
 134         uint32_t cpos = clog->cpos;
 135
 136         while (cpos && (cpos <= clog->cpos || cpos > (clog->cpos + CLOG_MAX_ENTRY_SIZE))) {
 137                 clog_entry_t *cur = (clog_entry_t *)((char *)clog + cpos);
 138                 clog_dump_entry(cur, cpos);
 139                 cpos = cur->prev;
 140         }
 141 }
 142
 143 void
 144 clog_dump_json(
 145         clog_base_t *clog,
 146         GString *str,
 147         const char *ident,
 148         guint max_entries)
 149 {
 150         g_return_if_fail(clog != NULL);
 151         g_return_if_fail(str != NULL);
 152
 153         guint64 ident_digest = 0;
 154
 155         if (ident && ident[0]) {
 156                 ident_digest = fnv_64a_buf(ident, strlen(ident) + 1, FNV1A_64_INIT);
 157         }
 158
 159         uint32_t cpos = clog->cpos;
 160
 161         g_string_append_printf(str, "{\n");
 162
 163         g_string_append_printf(str, "\"data\": [\n");
 164
 165         guint count = 0;
 166         while (cpos && (cpos <= clog->cpos || cpos > (clog->cpos + CLOG_MAX_ENTRY_SIZE))) {
 167                 clog_entry_t *cur = (clog_entry_t *)((char *)clog + cpos);
 168                 cpos = cur->prev;
 169
 170                 if (count >= max_entries)
 171                         break;
 172
 173                 if (ident_digest && ident_digest != cur->ident_digest)
 174                         continue;
 175
 176                 char *node = cur->data;
 177                 char *ident = node + cur->node_len;
 178                 char *tag = ident + cur->ident_len;
 179                 char *msg = tag + cur->tag_len;
 180
 181                 if (count)
 182                         g_string_append_printf(str, ",\n");
 183
 184                 g_string_append_printf(str, "{\"uid\": %u, \"time\": %u, \"pri\": %d, \"tag\": \"%s\", "
 185                                        "\"pid\": %u, \"node\": \"%s\", \"user\": \"%s\", "
 186                                        "\"msg\": \"%s\"}", cur->uid, cur->time, cur->priority, tag,
 187                                        cur->pid, node, ident, msg);
 188
 189                 count++;
 190
 191         }
 192
 193         if (count)
 194                 g_string_append_printf(str, "\n");
 195
 196         g_string_append_printf(str, "]\n");
 197         g_string_append_printf(str, "}\n");
 198
 199 }
 200
 201 uint32_t
 202 clog_entry_size(const clog_entry_t *entry)
 203 {
 204         g_return_val_if_fail(entry != NULL, 0);
 205
 206         return sizeof(clog_entry_t) + entry->node_len +
 207                 entry->ident_len + entry->tag_len + entry->msg_len;
 208 }
 209
 210 void
 211 clog_copy(
 212         clog_base_t *clog,
 213         const clog_entry_t *entry)
 214 {
 215         g_return_if_fail(clog != NULL);
 216         g_return_if_fail(entry != NULL);
 217
 218         uint32_t size = clog_entry_size(entry);
 219
 220         clog_entry_t *new;
 221         if ((new = clog_alloc_entry(clog, size)))
 222                 memcpy((char *)new + 8, (char *)entry + 8, size - 8);
 223 }
 224
 225 uint32_t
 226 clog_pack(
 227         clog_entry_t *entry,
 228         const char *node,
 229         const char *ident,
 230         const char *tag,
 231         uint32_t pid,
 232         time_t logtime,
 233         uint8_t priority,
 234         const char *msg)
 235 {
 236         g_return_val_if_fail(entry != NULL, 0);
 237         g_return_val_if_fail(ident != NULL, 0);
 238         g_return_val_if_fail(tag != NULL, 0);
 239         g_return_val_if_fail(msg != NULL, 0);
 240         g_return_val_if_fail(priority >= 0, 0);
 241         g_return_val_if_fail(priority < 8, 0);
 242
 243         uint8_t node_len = CFS_MIN(strlen(node) + 1, 255);
 244         uint8_t ident_len = CFS_MIN(strlen(ident) + 1, 255);
 245         uint8_t tag_len = CFS_MIN(strlen(tag) + 1, 255);
 246
 247         char *msg_start = entry->data + node_len + ident_len + tag_len;
 248         *msg_start = 0;
 249
 250         int buf_len = CLOG_MAX_ENTRY_SIZE - (msg_start - (char *)entry);
 251         utf8_to_ascii(msg_start, buf_len, msg, TRUE);
 252
 253         uint32_t msg_len = strlen(msg_start) + 1;
 254
 255         uint32_t size = sizeof(clog_entry_t) + node_len + ident_len +
 256                 tag_len + msg_len;
 257
 258         if (size > CLOG_MAX_ENTRY_SIZE) {
 259                 int diff = size - CLOG_MAX_ENTRY_SIZE;
 260                 msg_len -= diff;
 261                 size = CLOG_MAX_ENTRY_SIZE;
 262         }
 263
 264         entry->prev = 0;
 265         entry->next = 0;
 266         entry->uid = ++uid_counter;
 267         entry->time = logtime;
 268         entry->node_digest = fnv_64a_buf(node, node_len, FNV1A_64_INIT);
 269         entry->ident_digest = fnv_64a_buf(ident, ident_len, FNV1A_64_INIT);
 270         entry->pid = pid;
 271         entry->priority = priority;
 272         entry->node_len = node_len;
 273         entry->ident_len = ident_len;
 274         entry->tag_len = tag_len;
 275         entry->msg_len = msg_len;
 276
 277         char *p = entry->data;
 278         g_strlcpy(p, node, node_len);
 279         p = p + node_len;
 280         g_strlcpy(p, ident, ident_len);
 281         p = p + ident_len;
 282         g_strlcpy(p, tag, tag_len);
 283
 284         return size;
 285 }
 286
 287 clog_base_t *
 288 clog_new(uint32_t size)
 289 {
 290         g_return_val_if_fail(sizeof(clog_base_t) == 8, NULL);
 291
 292         if (!size)
 293                 size = CLOG_DEFAULT_SIZE;
 294
 295         g_return_val_if_fail(size >= (CLOG_MAX_ENTRY_SIZE*10), NULL);
 296
 297
 298         clog_base_t *clog = (clog_base_t *)g_malloc0(size);
 299         if (clog) {
 300                 clog->size = size;
 301         }
 302
 303         return clog;
 304 }
 305
 306 static gint
 307 clog_entry_sort_fn(
 308         gconstpointer v1,
 309         gconstpointer v2,
 310         gpointer user_data)
 311 {
 312         clog_entry_t *entry1 = (clog_entry_t *)v1;
 313         clog_entry_t *entry2 = (clog_entry_t *)v2;
 314
 315         if (entry1->time != entry2->time)
 316                 return entry1->time - entry2->time;
 317
 318         if (entry1->node_digest != entry2->node_digest)
 319                 return entry1->node_digest - entry2->node_digest;
 320
 321         return entry1->uid - entry2->uid;
 322 }
 323
 324 static gboolean
 325 clog_tree_foreach_fn(
 326         gpointer key,
 327         gpointer value,
 328         gpointer data)
 329 {
 330         clog_entry_t *entry = (clog_entry_t *)value;
 331         clog_base_t *clog = (clog_base_t *)data;
 332
 333         clog_copy(clog, entry);
 334
 335         return FALSE;
 336 }
 337
 338 clog_base_t *
 339 clog_sort(clog_base_t *clog)
 340 {
 341         g_return_val_if_fail(clog != NULL, NULL);
 342         g_return_val_if_fail(clog->cpos != 0, NULL);
 343
 344         clog_base_t *res = clog_new(clog->size);
 345         if (!res)
 346                 return NULL;
 347
 348         GTree *tree = g_tree_new_with_data(clog_entry_sort_fn, NULL);
 349         if (!tree) {
 350                 g_free(res);
 351                 return NULL;
 352         }
 353
 354         uint32_t cpos = clog->cpos;
 355
 356         while (cpos && (cpos <= clog->cpos || cpos > (clog->cpos + CLOG_MAX_ENTRY_SIZE))) {
 357                 clog_entry_t *cur = (clog_entry_t *)((char *)clog + cpos);
 358
 359                 g_tree_insert(tree, cur, cur);
 360
 361                 cpos = cur->prev;
 362         }
 363
 364         g_tree_foreach(tree, clog_tree_foreach_fn, res);
 365         g_tree_destroy(tree);
 366
 367         return res;
 368 }
 369
 370 uint32_t
 371 clog_size(clog_base_t *clog)
 372 {
 373         g_return_val_if_fail(clog != NULL, 0);
 374         return clog->size;
 375 }
 376
 377 static gboolean
 378 dedup_lookup(
 379         GHashTable *dedup,
 380         const clog_entry_t *entry)
 381 {
 382         g_return_val_if_fail(dedup != NULL, FALSE);
 383         g_return_val_if_fail(entry != NULL, FALSE);
 384
 385         dedup_entry_t *dd = g_hash_table_lookup(dedup, &entry->node_digest);
 386         if (!dd) {
 387                 if (!(dd = g_new0(dedup_entry_t, 1)))
 388                         return FALSE;
 389
 390                 dd->node_digest = entry->node_digest;
 391                 dd->time = entry->time;
 392                 dd->uid = entry->uid;
 393
 394                 g_hash_table_insert(dedup, dd, dd);
 395
 396                 return TRUE;
 397         }
 398
 399         if (entry->time > dd->time ||
 400             (entry->time == dd->time && entry->uid > dd->uid)) {
 401                 dd->time = entry->time;
 402                 dd->uid = entry->uid;
 403                 return TRUE;
 404         }
 405
 406         return FALSE;
 407 }
 408
 409 struct clusterlog {
 410         GHashTable *dedup;
 411         GMutex mutex;
 412         clog_base_t *base;
 413 };
 414
 415 void
 416 clusterlog_dump(
 417         clusterlog_t *cl,
 418         GString *str,
 419         const char *user,
 420         guint max_entries)
 421 {
 422         g_return_if_fail(cl != NULL);
 423         g_return_if_fail(str != NULL);
 424
 425         g_mutex_lock(&cl->mutex);
 426         clog_dump_json(cl->base, str, user, max_entries);
 427         g_mutex_unlock(&cl->mutex);
 428 }
 429
 430 clog_base_t *
 431 clusterlog_merge(
 432         clusterlog_t *cl,
 433         clog_base_t **clog,
 434         int count,
 435         int local_index)
 436 {
 437         g_return_val_if_fail(cl != NULL, NULL);
 438         g_return_val_if_fail(clog != NULL, NULL);
 439         g_return_val_if_fail(count >= 2, NULL);
 440         g_return_val_if_fail(local_index >= 0, NULL);
 441         g_return_val_if_fail(local_index < count, NULL);
 442
 443         uint32_t cpos[count];
 444         uint32_t maxsize = 0;
 445
 446         GHashTable *dedup;
 447         if (!(dedup = g_hash_table_new_full(g_int64_hash, g_int64_equal, NULL, g_free)))
 448                 return NULL;
 449
 450         GTree *tree = g_tree_new_with_data(clog_entry_sort_fn, NULL);
 451         if (!tree) {
 452                 g_hash_table_destroy(dedup);
 453                 return NULL;
 454         }
 455
 456         clog_base_t *res = clog_new(maxsize);
 457         if (!res) {
 458                 g_hash_table_destroy(dedup);
 459                 g_tree_destroy(tree);
 460                 return NULL;
 461         }
 462
 463         g_mutex_lock(&cl->mutex);
 464
 465         for (int i = 0; i < count; i++) {
 466                 if (i == local_index)
 467                         clog[i] = cl->base;
 468
 469                 if (!clog[i]) {
 470                         cfs_critical("log pointer is NULL!");
 471                         cpos[i] = 0;
 472                         continue;
 473                 }
 474                 cpos[i] = clog[i]->cpos;
 475                 if (clog[i]->size > maxsize)
 476                         maxsize = clog[i]->size;
 477         }
 478
 479         size_t logsize = 0;
 480         maxsize = res->size - sizeof(clog_base_t) - CLOG_MAX_ENTRY_SIZE;
 481
 482         int found = 0;
 483         while (found >= 0) {
 484
 485                 found = -1;
 486                 uint32_t last = 0;
 487
 488                 /* select entry wit latest time */
 489                 for (int i = 0; i < count; i++) {
 490                         if (!cpos[i])
 491                                 continue;
 492                         clog_entry_t *cur = (clog_entry_t *)((char *)clog[i] + cpos[i]);
 493                         if (cur->time > last) {
 494                                 last = cur->time;
 495                                 found = i;
 496                         }
 497                 }
 498
 499                 if (found < 0)
 500                         break;
 501
 502                 clog_entry_t *cur = (clog_entry_t *)((char *)clog[found] + cpos[found]);
 503
 504                 if (!g_tree_lookup(tree, cur)) {
 505                         g_tree_insert(tree, cur, cur);
 506                         dedup_lookup(dedup, cur); /* just to record versions */
 507                         logsize += cur->next - cpos[found];
 508                         if (logsize >= maxsize)
 509                                 break;
 510                 }
 511
 512                 if (!cur->prev) {
 513                         cpos[found] = 0;
 514                 } else {
 515                         cpos[found] = cur->prev;
 516                         if (!(cpos[found] <= clog[found]->cpos ||
 517                               cpos[found] > (clog[found]->cpos + CLOG_MAX_ENTRY_SIZE))) {
 518                                 cpos[found] = 0;
 519                         }
 520                 }
 521         }
 522
 523         g_tree_foreach(tree, clog_tree_foreach_fn, res);
 524         g_tree_destroy(tree);
 525
 526         g_hash_table_destroy(cl->dedup);
 527         cl->dedup = dedup;
 528
 529         g_free(cl->base);
 530         cl->base = res;
 531
 532         g_mutex_unlock(&cl->mutex);
 533
 534         return res;
 535 }
 536
 537 void
 538 clusterlog_destroy(clusterlog_t *cl)
 539 {
 540         g_return_if_fail(cl != NULL);
 541
 542         g_mutex_clear(&cl->mutex);
 543
 544         if (cl->base)
 545                 g_free(cl->base);
 546
 547         if (cl->dedup)
 548                 g_hash_table_destroy(cl->dedup);
 549
 550         g_free(cl);
 551 }
 552
 553 clusterlog_t *
 554 clusterlog_new(void)
 555 {
 556         clusterlog_t *cl = g_new0(clusterlog_t, 1);
 557         if (!cl)
 558                 return NULL;
 559
 560         g_mutex_init(&cl->mutex);
 561
 562         if (!(cl->base = clog_new(0)))
 563                 goto fail;
 564
 565         if (!(cl->dedup = g_hash_table_new_full(g_int64_hash, g_int64_equal, NULL, g_free)))
 566                 goto fail;
 567
 568         return cl;
 569
 570 fail:
 571         clusterlog_destroy(cl);
 572         return NULL;
 573 }
 574
 575 gpointer
 576 clusterlog_get_state(
 577         clusterlog_t *cl,
 578         unsigned int *res_len)
 579 {
 580         g_return_val_if_fail(cl != NULL, NULL);
 581         g_return_val_if_fail(res_len != NULL, NULL);
 582
 583         g_mutex_lock(&cl->mutex);
 584
 585         clog_base_t *new;
 586         if ((new = clog_sort(cl->base))) {
 587                 g_free(cl->base);
 588                 cl->base = new;
 589         }
 590
 591         *res_len = clog_size(cl->base);
 592         gpointer msg = g_memdup(cl->base, *res_len);
 593
 594         g_mutex_unlock(&cl->mutex);
 595
 596         return msg;
 597 }
 598
 599 void
 600 clusterlog_insert(
 601         clusterlog_t *cl,
 602         const clog_entry_t *entry)
 603 {
 604         g_return_if_fail(cl != NULL);
 605         g_return_if_fail(entry != NULL);
 606
 607         g_mutex_lock(&cl->mutex);
 608
 609         if (dedup_lookup(cl->dedup, entry)) {
 610                 clog_copy(cl->base, entry);
 611         } else {
 612                 cfs_message("ignore duplicate"); // fixme remove
 613         }
 614
 615         g_mutex_unlock(&cl->mutex);
 616 }
 617
 618 void
 619 clusterlog_add(
 620         clusterlog_t *cl,
 621         const char *ident,
 622         const char *tag,
 623         uint32_t pid,
 624         uint8_t priority,
 625         const gchar *format,
 626         ...)
 627 {
 628         g_return_if_fail(cl != NULL);
 629         g_return_if_fail(format != NULL);
 630
 631         va_list args;
 632         va_start (args, format);
 633         char *msg = g_strdup_vprintf (format, args);
 634         va_end (args);
 635
 636         time_t ctime = time(NULL);
 637         clog_entry_t *entry = (clog_entry_t *)alloca(CLOG_MAX_ENTRY_SIZE);
 638         uint32_t size = clog_pack(entry, cfs.nodename, ident, tag, pid, ctime, priority, msg);
 639         g_free(msg);
 640
 641         if (!size)
 642                 return;
 643
 644         clusterlog_insert(cl, entry);
 645 }
 646