core-log.c

   1 /*
   2  * Copyright Neil Brown ©2020-2023 <neil@brown.name>
   3  * May be distributed under terms of GPLv2 - see file:COPYING
   4  *
   5  * Logging support.
   6  *
   7  * Provide log() and related functions to collect trace data.
   8  * Store it in a buffer accessible as a document, and optionally
   9  * write to a file or stderr.
  10  *
  11  */
  12
  13 #include <unistd.h>
  14 #include <stdlib.h>
  15 #include <stdio.h>
  16 #include <stdarg.h>
  17 #include <sys/time.h>
  18
  19 #define PRIVATE_DOC_REF
  20 struct doc_ref {
  21         struct logbuf *b;
  22         unsigned int o;
  23 };
  24 #define DOC_DATA_TYPE struct log
  25 #define DOC_NEXT(p,m,r,b) log_next(p,r,b)
  26 #define DOC_PREV(p,m,r,b) log_prev(p,r,b)
  27
  28 #include "core.h"
  29 #include "internal.h"
  30
  31 struct logbuf {
  32         struct list_head h;
  33         unsigned int    end;
  34         char            text[];
  35 };
  36
  37 struct log {
  38         struct doc              doc;
  39         struct list_head        log;
  40         int                     blocked;
  41         int                     refresh_active;
  42         FILE                    *log_file;
  43 };
  44
  45 #include "core-pane.h"
  46
  47 static struct pane *log_pane;
  48
  49 #define LBSIZE (8192 - sizeof(struct logbuf))
  50
  51 static struct logbuf *safe get_new_buf(struct log *d safe)
  52 {
  53         struct logbuf *b = malloc(sizeof(*b) + LBSIZE);
  54
  55         list_add_tail(&b->h, &d->log);
  56         b->end = 0;
  57         return b;
  58 }
  59
  60 static struct logbuf *safe get_buf(struct log *d safe)
  61 {
  62         if (!list_empty(&d->log)) {
  63                 struct logbuf *b;
  64                 b = list_last_entry(&d->log, struct logbuf, h);
  65                 if (b->end < LBSIZE)
  66                         return b;
  67         }
  68         return get_new_buf(d);
  69 }
  70
  71 void LOG(char *fmt, ...)
  72 {
  73         va_list ap;
  74         unsigned int n;
  75         struct log *ld;
  76         struct logbuf *b;
  77         struct timeval now;
  78
  79         if (!log_pane)
  80                 /* too early */
  81                 return;
  82         if (!fmt)
  83                 return;
  84         ld = log_pane->doc_data;
  85         if (ld->refresh_active) {
  86                 /* Mustn't log anything if doc is being viewed */
  87                 if (pane_notify("doc:notify-viewers", log_pane))
  88                         return;
  89         }
  90         if (ld->blocked)
  91                 return;
  92         ld->blocked = 1;
  93         gettimeofday(&now, NULL);
  94         b = get_buf(ld);
  95         va_start(ap, fmt);
  96         if (edlib_testing(log_pane))
  97                 n = 0;
  98         else
  99                 n = snprintf(b->text + b->end, LBSIZE - b->end - 1,
 100                              "%ld.%03ld:",
 101                              now.tv_sec % 10000, now.tv_usec / 1000);
 102         if (n < LBSIZE - b->end - 1)
 103                 n += vsnprintf(b->text + b->end + n, LBSIZE - b->end - 1 - n,
 104                                fmt, ap);
 105         va_end(ap);
 106
 107         if (b->end != 0 && n >= LBSIZE - b->end - 1) {
 108                 /* Didn't fit, allocate new buf */
 109                 b = get_new_buf(ld);
 110                 va_start(ap, fmt);
 111                 if (edlib_testing(log_pane))
 112                         n = 0;
 113                 else
 114                         n = snprintf(b->text, LBSIZE - 1, "%ld.%03ld:",
 115                                      now.tv_sec % 10000,
 116                                      now.tv_usec / 1000);
 117                 if (n < LBSIZE - 1)
 118                         n += vsnprintf(b->text + n, LBSIZE - 1 - n, fmt, ap);
 119                 va_end(ap);
 120         }
 121         if (n >= LBSIZE - 1) {
 122                 /* Too long for buffer - truncate */
 123                 n = LBSIZE - 2;
 124         }
 125         b->text[b->end + n++] = '\n';
 126         b->text[b->end + n] = '\0';
 127
 128         if (ld->log_file) {
 129                 fwrite(b->text + b->end, 1, n, ld->log_file);
 130                 fflush(ld->log_file);
 131         }
 132         b->end += n;
 133         pane_notify("doc:replaced", log_pane, 1);
 134         ld->blocked = 0;
 135 }
 136
 137 DEF_CMD(log_append)
 138 {
 139         struct log *l = ci->home->doc_data;
 140         struct logbuf *b;
 141         unsigned int len;
 142
 143         if (!ci->str)
 144                 return Enoarg;
 145         len = strlen(ci->str);
 146
 147         b = get_buf(l);
 148
 149         if (b->end != 0 && len >= LBSIZE - b->end - 1) {
 150                 /* Doesn't fit, allocate new buf */
 151                 b = get_new_buf(l);
 152                 if (len >= LBSIZE-1)
 153                         len = LBSIZE-2;
 154         }
 155         strncpy(b->text + b->end, ci->str, len);
 156
 157         b->text[b->end + len++] = '\n';
 158         b->text[b->end + len] = '\0';
 159
 160         b->end += len;
 161         pane_notify("doc:replaced", ci->home, 1);
 162         return 1;
 163 }
 164
 165 DEF_CMD(log_content)
 166 {
 167         struct log *log = ci->home->doc_data;
 168         struct mark *from = ci->mark, *to = ci->mark2;
 169         struct mark *m;
 170         struct logbuf *b, *first, *last;
 171         int head, tail;
 172         int size = 0;
 173         int bytes = strcmp(ci->key, "doc:content-bytes") == 0;
 174
 175         if (!from)
 176                 return Enoarg;
 177         m = mark_dup(from);
 178         head = 0;
 179         first = from->ref.b;
 180         if (first)
 181                 head = from->ref.o;
 182         last = NULL;
 183         tail = 0;
 184         if (to) {
 185                 if (to->ref.b) {
 186                         last = to->ref.b;
 187                         tail = to->ref.o;
 188                 }
 189
 190                 b = first;
 191                 list_for_each_entry_from(b, &log->log, h) {
 192                         if (b == last)
 193                                 break;
 194                         size += b->end;
 195                 }
 196                 size += tail - head;
 197         }
 198
 199         b = first;
 200         list_for_each_entry_from(b, &log->log, h) {
 201                 struct mark *m2;
 202                 const char *s = b->text + head;
 203                 int ln = b->end - head;
 204
 205                 if (b == last)
 206                         ln = tail - head;
 207
 208                 if (m->ref.b != b) {
 209                         while ((m2 = mark_next(m)) &&
 210                                m2->ref.b == m->ref.b)
 211                                 mark_to_mark(m, m2);
 212                         m->ref.b = b;
 213                         m->ref.o = 0;
 214                 }
 215                 while (ln > 0) {
 216                         int rv;
 217                         const char *ss = s;
 218                         wint_t wc;
 219
 220                         if (bytes)
 221                                 wc = *s++;
 222                         else
 223                                 wc = get_utf8(&s, s+ln);
 224                         if (wc >= WERR)
 225                                 break;
 226
 227                         while ((m2 = mark_next(m)) &&
 228                                m2->ref.b == m->ref.b &&
 229                                m2->ref.o <= s - b->text)
 230                                 mark_to_mark(m, m2);
 231                         m->ref.o = s - b->text;
 232
 233                         ln -= s - ss;
 234                         rv = comm_call(ci->comm2, "consume", ci->focus,
 235                                        wc, m, s, ln, NULL, NULL, size, 0);
 236                         size = 0;
 237                         if (rv <= 0 || rv > ln + 1) {
 238                                 ln = 0;
 239                                 b = last;
 240                         }
 241                         if (rv > 1) {
 242                                 s += rv - 1;
 243                                 ln -= rv - 1;
 244                         }
 245                 }
 246                 head = 0;
 247                 if (b == last)
 248                         break;
 249         }
 250         mark_free(m);
 251         return 1;
 252 }
 253
 254 DEF_CMD(log_set_ref)
 255 {
 256         struct log *log = ci->home->doc_data;
 257         struct mark *m = ci->mark;
 258
 259         if (!m)
 260                 return Enoarg;
 261         mark_to_end(ci->home, m, ci->num != 1);
 262         m->ref.o = 0;
 263         if (ci->num == 1)
 264                 m->ref.b = list_first_entry_or_null(&log->log, struct logbuf, h);
 265         else
 266                 m->ref.b = NULL;
 267         return 1;
 268 }
 269
 270 static inline wint_t log_next(struct pane *p safe, struct doc_ref *r safe, bool bytes)
 271 {
 272         struct log *log = p->doc_data;
 273         wint_t ret;
 274
 275         if (!r->b)
 276                 ret = WEOF;
 277         else {
 278                 const char *s = &r->b->text[r->o];
 279
 280                 if (bytes)
 281                         ret = *s++;
 282                 else
 283                         ret = get_utf8(&s, r->b->text + r->b->end);
 284                 r->o = s - r->b->text;
 285                 if (r->o >= r->b->end) {
 286                         if (r->b == list_last_entry(&log->log,
 287                                                      struct logbuf, h))
 288                                 r->b = NULL;
 289                         else
 290                                 r->b = list_next_entry(r->b, h);
 291                         r->o = 0;
 292                 }
 293         }
 294         return ret;
 295 }
 296
 297 static inline wint_t log_prev(struct pane *p safe, struct doc_ref *r safe, bool bytes)
 298 {
 299         struct log *log = p->doc_data;
 300         const char *s;
 301
 302         if (list_empty(&log->log))
 303                 return WEOF;
 304         else if (!r->b) {
 305                 r->b = list_last_entry(&log->log, struct logbuf, h);
 306                 r->o = r->b->end;
 307         } else if (r->o == 0) {
 308                 if (r->b != list_first_entry(&log->log,
 309                                               struct logbuf, h)) {
 310                         r->b = list_prev_entry(r->b, h);
 311                         r->o = r->b->end;
 312                 } else
 313                         return WEOF;
 314         }
 315         if (bytes)
 316                 r->o -= 1;
 317         else
 318                 r->o = utf8_round_len(r->b->text, r->o - 1);
 319         s = r->b->text + r->o;
 320         if (bytes)
 321                 return *s;
 322         else
 323                 return get_utf8(&s, r->b->text + r->b->end);
 324 }
 325
 326 DEF_CMD(log_char)
 327 {
 328         return do_char_byte(ci);
 329 }
 330
 331 DEF_CMD(log_val_marks)
 332 {
 333         /* mark1 and mark2 must be correctly ordered */
 334         struct log *log = ci->home->doc_data;
 335         struct logbuf *b;
 336         int found = 0;
 337
 338         if (!ci->mark || !ci->mark2)
 339                 return Enoarg;
 340
 341         if (ci->mark->ref.b == ci->mark2->ref.b) {
 342                 if (ci->mark->ref.o < ci->mark2->ref.o)
 343                         return 1;
 344                 LOG("log_val_marks: same buf, bad offset: %d, %d",
 345                     ci->mark->ref.o, ci->mark2->ref.o);
 346                 return Efalse;
 347         }
 348         if (ci->mark->ref.b == NULL) {
 349                 LOG("log_val_marks: mark.b is NULL");
 350                 return Efalse;
 351         }
 352         found = 0;
 353         list_for_each_entry(b, &log->log, h) {
 354                 if (ci->mark->ref.b == b)
 355                         found = 1;
 356                 if (ci->mark2->ref.b == b) {
 357                         if (found == 1)
 358                                 return 1;
 359                         LOG("log_val_marks: mark2.b found before mark1");
 360                         return Efalse;
 361                 }
 362         }
 363         if (ci->mark2->ref.b == NULL) {
 364                 if (found == 1)
 365                         return 1;
 366                 LOG("log_val_marks: mark2.b (NULL) found before mark1");
 367                 return Efalse;
 368         }
 369         if (found == 0)
 370                 LOG("log_val_marks: Neither mark found in buf list");
 371         if (found == 1)
 372                 LOG("log_val_marks: mark2 not found in buf list");
 373         return Efalse;
 374 }
 375
 376 DEF_CMD(log_destroy)
 377 {
 378         /* Not allowed to destroy this document
 379          * So handle command here, so we don't get
 380          * to the default handler
 381          */
 382         return 1;
 383 }
 384
 385 DEF_CMD(log_view)
 386 {
 387         if (!log_pane)
 388                 return Enoarg;
 389         /* Not sure what I want here yet */
 390         attr_set_str(&log_pane->attrs, "render-default", "text");
 391         attr_set_str(&log_pane->attrs, "doc-type", "text");
 392         attr_set_str(&log_pane->attrs, "view-default", "viewer");
 393         call("doc:set-name", log_pane, 0, NULL, "*Debug Log*");
 394         call("global-multicall-doc:appeared-", log_pane);
 395         return 1;
 396 }
 397
 398 DEF_CMD_CLOSED(log_close)
 399 {
 400         struct log *l = ci->home->doc_data;
 401
 402         while (!list_empty(&l->log)) {
 403                 struct logbuf *b = list_first_entry(&l->log, struct logbuf, h);
 404                 list_del(&b->h);
 405                 free(b);
 406         }
 407         if (l->log_file && l->log_file != stderr)
 408                 fclose(l->log_file);
 409         return 1;
 410 }
 411
 412 DEF_CMD(log_refresh_active)
 413 {
 414         struct log *l = ci->home->doc_data;
 415
 416         l->refresh_active = ci->num;
 417         return 1;
 418 }
 419
 420 static struct map *log_map;
 421 DEF_LOOKUP_CMD(log_handle, log_map);
 422
 423 DEF_CMD(log_new)
 424 {
 425         struct log *l;
 426         struct pane *p;
 427
 428         if (!ci->str)
 429                 return Enoarg;
 430
 431         p = doc_register(ci->focus, &log_handle.c);
 432         if (!p)
 433                 return Efail;
 434         l = p->doc_data;
 435         INIT_LIST_HEAD(&l->log);
 436         attr_set_str(&p->attrs, "render-default", "text");
 437         attr_set_str(&p->attrs, "doc-type", "text");
 438         attr_set_str(&p->attrs, "render-default", "text");
 439         call("doc:set-name", p, 0, NULL, ci->str);
 440         call("global-multicall-doc:appeared-", p);
 441         comm_call(ci->comm2, "cb", p);
 442         return 1;
 443 }
 444
 445 static void log_init(struct pane *ed safe)
 446 {
 447         char *fname;
 448         struct log *ld;
 449
 450         log_pane = doc_register(ed, &log_handle.c);
 451         if (!log_pane)
 452                 return;
 453         ld = log_pane->doc_data;
 454         if (edlib_testing(ed))
 455                 /* line-count is SYNC when testing, and log can
 456                  * get big - so disable
 457                  */
 458                 attr_set_str(&log_pane->attrs, "linecount-disable", "yes");
 459
 460         INIT_LIST_HEAD(&ld->log);
 461
 462         call("editor:request:Refresh-active", log_pane);
 463
 464         fname = getenv("EDLIB_LOG");
 465         if (!fname || !*fname)
 466                 return;
 467         if (strcmp(fname, "stderr") == 0) {
 468                 ld->log_file = stderr;
 469                 return;
 470         }
 471
 472         ld->log_file = fopen(fname, "a");
 473         if (!ld->log_file)
 474                 LOG("log: Cannot open \"%s\" for logging\n", fname);
 475 }
 476
 477 void log_setup(struct pane *ed safe)
 478 {
 479         log_map = key_alloc();
 480
 481         key_add_chain(log_map, doc_default_cmd);
 482         key_add(log_map, "doc:content", &log_content);
 483         key_add(log_map, "doc:content-bytes", &log_content);
 484         key_add(log_map, "doc:set-ref", &log_set_ref);
 485         key_add(log_map, "doc:char", &log_char);
 486         key_add(log_map, "doc:destroy", &log_destroy);
 487         key_add(log_map, "doc:log:append", &log_append);
 488         key_add(log_map, "Close", &log_close);
 489         key_add(log_map, "Refresh-active", &log_refresh_active);
 490         if(0)key_add(log_map, "debug:validate-marks", &log_val_marks);
 491
 492         log_init(ed);
 493         call_comm("global-set-command", ed, &log_view, 0, NULL,
 494                   "interactive-cmd-view-log");
 495         call_comm("global-set-command", ed, &log_new, 0, NULL,
 496                   "log:create");
 497         LOG("log: testing 1 %d 3 Α Β Ψ α β γ", 2);
 498 }