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