src/shared/logprint.c

   1 /*
   2  * DLOG
   3  * Copyright (c) 2005-2008, The Android Open Source Project
   4  * Copyright (c) 2012-2013 Samsung Electronics Co., Ltd.
   5  *
   6  * Licensed under the Apache License, Version 2.0 (the License);
   7  * you may not use this file except in compliance with the License.
   8  * You may obtain a copy of the License at
   9  *
  10  *     http://www.apache.org/licenses/LICENSE-2.0
  11  *
  12  * Unless required by applicable law or agreed to in writing, software
  13  * distributed under the License is distributed on an "AS IS" BASIS,
  14  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  15  * See the License for the specific language governing permissions and
  16  * limitations under the License.
  17  */
  18
  19 #include <stdio.h>
  20 #include <stdlib.h>
  21 #include <string.h>
  22 #include <assert.h>
  23 #include <errno.h>
  24 #include <ctype.h>
  25 #include <unistd.h>
  26
  27 #include <logprint.h>
  28
  29
  30 typedef struct FilterInfo_t {
  31         char *mTag;
  32         log_priority mPri;
  33         struct FilterInfo_t *p_next;
  34 } FilterInfo;
  35
  36 struct log_format_t {
  37         log_priority global_pri;
  38         FilterInfo *filters;
  39         log_print_format format;
  40 };
  41
  42 static FilterInfo * filterinfo_new(const char *tag, log_priority pri)
  43 {
  44         FilterInfo *p_ret;
  45
  46         if (!tag)
  47                 return NULL;
  48
  49         p_ret = (FilterInfo *)calloc(1, sizeof(FilterInfo));
  50         if (!p_ret)
  51                 return NULL;
  52
  53         p_ret->mTag = strdup(tag);
  54         p_ret->mPri = pri;
  55
  56         return p_ret;
  57 }
  58
  59 static void filterinfo_free(FilterInfo *p_info)
  60 {
  61         if (p_info == NULL) {
  62                 return;
  63         }
  64
  65         free(p_info->mTag);
  66         p_info->mTag = NULL;
  67 }
  68
  69 /*
  70  * Note: also accepts 0-9 priorities
  71  * returns DLOG_UNKNOWN if the character is unrecognized
  72  */
  73 static log_priority filter_char_to_pri (char c)
  74 {
  75         log_priority pri;
  76
  77         c = tolower(c);
  78
  79         if (c >= '0' && c <= '9') {
  80                 if (c >= ('0'+DLOG_SILENT)) {
  81                         pri = DLOG_VERBOSE;
  82                 } else {
  83                         pri = (log_priority)(c - '0');
  84                 }
  85         } else if (c == 'v') {
  86                 pri = DLOG_VERBOSE;
  87         } else if (c == 'd') {
  88                 pri = DLOG_DEBUG;
  89         } else if (c == 'i') {
  90                 pri = DLOG_INFO;
  91         } else if (c == 'w') {
  92                 pri = DLOG_WARN;
  93         } else if (c == 'e') {
  94                 pri = DLOG_ERROR;
  95         } else if (c == 'f') {
  96                 pri = DLOG_FATAL;
  97         } else if (c == 's') {
  98                 pri = DLOG_SILENT;
  99         } else if (c == '*') {
 100                 pri = DLOG_DEFAULT;
 101         } else {
 102                 pri = DLOG_UNKNOWN;
 103         }
 104
 105         return pri;
 106 }
 107
 108 static char filter_pri_to_char (log_priority pri)
 109 {
 110         switch (pri) {
 111         case DLOG_VERBOSE:
 112                 return 'V';
 113         case DLOG_DEBUG:
 114                 return 'D';
 115         case DLOG_INFO:
 116                 return 'I';
 117         case DLOG_WARN:
 118                 return 'W';
 119         case DLOG_ERROR:
 120                 return 'E';
 121         case DLOG_FATAL:
 122                 return 'F';
 123         case DLOG_SILENT:
 124                 return 'S';
 125         case DLOG_DEFAULT:
 126         case DLOG_UNKNOWN:
 127         default:
 128                 return '?';
 129         }
 130 }
 131
 132 static log_priority filter_pri_for_tag(log_format *p_format, const char *tag)
 133 {
 134         FilterInfo *p_curFilter;
 135
 136         for (p_curFilter = p_format->filters; p_curFilter != NULL; p_curFilter = p_curFilter->p_next )
 137         {
 138                 if (0 == strcmp(tag, p_curFilter->mTag))
 139                 {
 140                         if (p_curFilter->mPri == DLOG_DEFAULT) {
 141                                 return p_format->global_pri;
 142                         } else {
 143                                 return p_curFilter->mPri;
 144                         }
 145                 }
 146         }
 147         return p_format->global_pri;
 148 }
 149
 150 /** for debugging */
 151 void dump_filters(log_format *p_format)
 152 {
 153         FilterInfo *p_fi;
 154
 155         for (p_fi = p_format->filters ; p_fi != NULL ; p_fi = p_fi->p_next) {
 156                 char cPri = filter_pri_to_char(p_fi->mPri);
 157                 if (p_fi->mPri == DLOG_DEFAULT) {
 158                         cPri = filter_pri_to_char(p_format->global_pri);
 159                 }
 160                 fprintf(stderr, "%s:%c\n", p_fi->mTag, cPri);
 161         }
 162
 163         fprintf(stderr, "*:%c\n", filter_pri_to_char(p_format->global_pri));
 164
 165 }
 166
 167 /**
 168  * returns 1 if this log line should be printed based on its priority
 169  * and tag, and 0 if it should not
 170  */
 171 int log_should_print_line (log_format *p_format, const char *tag, log_priority pri)
 172 {
 173         return pri >= filter_pri_for_tag(p_format, tag);
 174 }
 175
 176 log_format *log_format_new()
 177 {
 178         log_format *p_ret;
 179
 180         p_ret = calloc(1, sizeof(log_format));
 181
 182         if (!p_ret)
 183                 return NULL;
 184         p_ret->global_pri = DLOG_SILENT;
 185         p_ret->format = FORMAT_BRIEF;
 186
 187         return p_ret;
 188 }
 189
 190 void log_format_free(log_format *p_format)
 191 {
 192         FilterInfo *p_info, *p_info_old;
 193
 194         p_info = p_format->filters;
 195
 196         while (p_info != NULL) {
 197                 p_info_old = p_info;
 198                 p_info = p_info->p_next;
 199                 filterinfo_free(p_info_old);
 200         }
 201
 202         free(p_format);
 203 }
 204
 205 void log_set_print_format(log_format *p_format,log_print_format format)
 206 {
 207         p_format->format=format;
 208 }
 209
 210 /**
 211  * Returns FORMAT_OFF on invalid string
 212  */
 213 log_print_format log_format_from_string(const char * formatString)
 214 {
 215         static log_print_format format;
 216
 217         if (strcmp(formatString, "brief") == 0)
 218                 format = FORMAT_BRIEF;
 219         else if (strcmp(formatString, "process") == 0)
 220                 format = FORMAT_PROCESS;
 221         else if (strcmp(formatString, "tag") == 0)
 222                 format = FORMAT_TAG;
 223         else if (strcmp(formatString, "thread") == 0)
 224                 format = FORMAT_THREAD;
 225         else if (strcmp(formatString, "raw") == 0)
 226                 format = FORMAT_RAW;
 227         else if (strcmp(formatString, "time") == 0)
 228                 format = FORMAT_TIME;
 229         else if (strcmp(formatString, "threadtime") == 0)
 230                 format = FORMAT_THREADTIME;
 231         else if (strcmp(formatString, "dump") == 0)
 232                 format = FORMAT_DUMP;
 233         else if (strcmp(formatString, "long") == 0)
 234                 format = FORMAT_LONG;
 235         else format = FORMAT_OFF;
 236
 237         return format;
 238 }
 239
 240 /**
 241  * filterExpression: a single filter expression
 242  * eg "AT:d"
 243  *
 244  * returns 0 on success and -1 on invalid expression
 245  *
 246  * Assumes single threaded execution
 247  */
 248 int log_add_filter_rule(log_format *p_format,
 249                 const char *filterExpression)
 250 {
 251         size_t tagNameLength;
 252         log_priority pri = DLOG_DEFAULT;
 253
 254         tagNameLength = strcspn(filterExpression, ":");
 255
 256         if (!p_format) {
 257                 goto error;
 258         }
 259
 260         if (tagNameLength == 0) {
 261                 goto error;
 262         }
 263
 264         if(filterExpression[tagNameLength] == ':') {
 265                 pri = filter_char_to_pri(filterExpression[tagNameLength+1]);
 266
 267                 if (pri == DLOG_UNKNOWN) {
 268                         goto error;
 269                 }
 270         }
 271
 272         if(0 == strncmp("*", filterExpression, tagNameLength)) {
 273                 /* This filter expression refers to the global filter
 274                  * The default level for this is DEBUG if the priority
 275                  * is unspecified
 276                  */
 277                 if (pri == DLOG_DEFAULT) {
 278                         pri = DLOG_DEBUG;
 279                 }
 280
 281                 p_format->global_pri = pri;
 282         } else {
 283                 /* for filter expressions that don't refer to the global
 284                  * filter, the default is verbose if the priority is unspecified
 285                  */
 286                 if (pri == DLOG_DEFAULT) {
 287                         pri = DLOG_VERBOSE;
 288                 }
 289
 290                 char *tagName;
 291                 tagName = strndup(filterExpression, tagNameLength);
 292
 293                 FilterInfo *p_fi = filterinfo_new(tagName, pri);
 294                 free(tagName);
 295
 296                 if (!p_fi)
 297                         goto  error;
 298                 p_fi->p_next = p_format->filters;
 299                 p_format->filters = p_fi;
 300         }
 301
 302         return 0;
 303 error:
 304         return -1;
 305 }
 306
 307 /**
 308  * filterString: a comma/whitespace-separated set of filter expressions
 309  *
 310  * eg "AT:d *:i"
 311  *
 312  * returns 0 on success and -1 on invalid expression
 313  *
 314  * Assumes single threaded execution
 315  *
 316  */
 317 int log_add_filter_string(log_format *p_format,
 318                 const char *filterString)
 319 {
 320         char *filterStringCopy = strdup (filterString);
 321         char *p_cur = filterStringCopy;
 322         char *p_ret;
 323         int err;
 324
 325         while (NULL != (p_ret = strsep(&p_cur, " \t,"))) {
 326                 /* ignore whitespace-only entries */
 327                 if(p_ret[0] != '\0') {
 328                         err = log_add_filter_rule(p_format, p_ret);
 329
 330                         if (err < 0) {
 331                                 goto error;
 332                         }
 333                 }
 334         }
 335
 336         free (filterStringCopy);
 337         return 0;
 338 error:
 339         free (filterStringCopy);
 340         return -1;
 341 }
 342
 343 static inline char * strip_end(char *str)
 344 {
 345         char *end = str + strlen(str) - 1;
 346
 347         while (end >= str && isspace(*end))
 348                 *end-- = '\0';
 349         return str;
 350 }
 351
 352 /**
 353  * Splits a wire-format buffer into an LogEntry
 354  * entry allocated by caller. Pointers will point directly into buf
 355  *
 356  * Returns 0 on success and -1 on invalid wire format (entry will be
 357  * in unspecified state)
 358  */
 359 int log_process_log_buffer(struct logger_entry *buf, log_entry *entry)
 360 {
 361         int i, start = -1, end = -1;
 362
 363         if (buf->len < 3) {
 364                 fprintf(stderr, "Entry too small\n");
 365                 return -1;
 366         }
 367
 368         entry->tv_sec = buf->sec;
 369         entry->tv_nsec = buf->nsec;
 370         entry->pid = buf->pid;
 371         entry->tid = buf->tid;
 372
 373         entry->priority = buf->msg[0];
 374         if (entry->priority < 0 || entry->priority > DLOG_SILENT) {
 375                 fprintf(stderr, "Wrong priority message\n");
 376                 return -1;
 377         }
 378
 379         entry->tag = buf->msg + 1;
 380         if (!strlen(entry->tag)) {
 381                 fprintf(stderr, "No tag message\n");
 382                 return -1;
 383         }
 384
 385         for (i = 0; i < buf->len; i++) {
 386                 if (buf->msg[i] == '\0') {
 387                         if (start == -1) {
 388                                 start = i + 1;
 389                         } else {
 390                                 end = i;
 391                                 break;
 392                         }
 393                 }
 394         }
 395         if (start == -1) {
 396                 fprintf(stderr, "Malformed log message\n");
 397                 return -1;
 398         }
 399         if (end == -1) {
 400                 end = buf->len - 1;
 401                 buf->msg[end] = '\0';
 402         }
 403
 404         entry->message = buf->msg + start;
 405         entry->messageLen = end - start;
 406
 407         return 0;
 408 }
 409
 410 /**
 411  * Formats a log message into a buffer
 412  *
 413  * Uses defaultBuffer if it can, otherwise malloc()'s a new buffer
 414  * If return value != defaultBuffer, caller must call free()
 415  * Returns NULL on malloc error
 416  */
 417 char *log_format_log_line (
 418                 log_format *p_format,
 419                 char *defaultBuffer,
 420                 size_t defaultBufferSize,
 421                 const log_entry *entry,
 422                 size_t *p_outLength)
 423 {
 424 #if defined(HAVE_LOCALTIME_R)
 425         struct tm tmBuf;
 426 #endif
 427         struct tm* ptm;
 428         char timeBuf[32], tzBuf[16];
 429         char prefixBuf[128], suffixBuf[128];
 430         char priChar;
 431         int prefixSuffixIsHeaderFooter = 0;
 432         char * ret = NULL;
 433
 434         priChar = filter_pri_to_char(entry->priority);
 435
 436         /*
 437          * Get the current date/time in pretty form
 438          *
 439          * It's often useful when examining a log with "less" to jump to
 440          * a specific point in the file by searching for the date/time stamp.
 441          * For this reason it's very annoying to have regexp meta characters
 442          * in the time stamp.  Don't use forward slashes, parenthesis,
 443          * brackets, asterisks, or other special chars here.
 444          */
 445 #if defined(HAVE_LOCALTIME_R)
 446         ptm = localtime_r(&(entry->tv_sec), &tmBuf);
 447 #else
 448         ptm = localtime(&(entry->tv_sec));
 449 #endif
 450         if (!ptm)
 451                 return ret;
 452
 453         strftime(timeBuf, sizeof(timeBuf), "%m-%d %H:%M:%S", ptm);
 454         strftime(tzBuf, sizeof(tzBuf), "%z", ptm);
 455
 456         /*
 457          * Construct a buffer containing the log header and log message.
 458          */
 459         size_t prefixLen, suffixLen;
 460
 461         switch (p_format->format) {
 462         case FORMAT_TAG:
 463                 prefixLen = snprintf(prefixBuf, sizeof(prefixBuf),
 464                                 "%c/%-8s: ", priChar, entry->tag);
 465                 strcpy(suffixBuf, "\n"); suffixLen = 1;
 466                 break;
 467         case FORMAT_PROCESS:
 468                 prefixLen = snprintf(prefixBuf, sizeof(prefixBuf),
 469                                 "%c(%5d) ", priChar, (int)entry->pid);
 470                 suffixLen = snprintf(suffixBuf, sizeof(suffixBuf),
 471                                 "  (%s)\n", entry->tag);
 472                 break;
 473         case FORMAT_THREAD:
 474                 prefixLen = snprintf(prefixBuf, sizeof(prefixBuf),
 475                                 "%c(%5d:%5d) ", priChar, (int)entry->pid, (int)entry->tid);
 476                 strcpy(suffixBuf, "\n");
 477                 suffixLen = 1;
 478                 break;
 479         case FORMAT_RAW:
 480                 prefixBuf[0] = 0;
 481                 prefixLen = 0;
 482                 strcpy(suffixBuf, "\n");
 483                 suffixLen = 1;
 484                 break;
 485         case FORMAT_TIME:
 486                 prefixLen = snprintf(prefixBuf, sizeof(prefixBuf),
 487                                 "%s.%03ld%s %c/%-8s(%5d): ", timeBuf, entry->tv_nsec / 1000000,
 488                                 tzBuf, priChar, entry->tag, (int)entry->pid);
 489                 strcpy(suffixBuf, "\n");
 490                 suffixLen = 1;
 491                 break;
 492         case FORMAT_THREADTIME:
 493                 prefixLen = snprintf(prefixBuf, sizeof(prefixBuf),
 494                                 "%s.%03ld%s %5d %5d %c %-8s: ", timeBuf, entry->tv_nsec / 1000000,
 495                                 tzBuf, (int)entry->pid, (int)entry->tid, priChar, entry->tag);
 496                 strcpy(suffixBuf, "\n");
 497                 suffixLen = 1;
 498                 break;
 499         case FORMAT_DUMP:
 500                 prefixLen = snprintf(prefixBuf, sizeof(prefixBuf),
 501                                 "%s.%03ld%s %5d %5d %c %-8s: ", timeBuf,
 502                                 entry->tv_nsec / 1000000, tzBuf, (int)entry->pid,
 503                                 (int)entry->tid, priChar, entry->tag);
 504                 strcpy(suffixBuf, "\n");
 505                 suffixLen = 1;
 506                 break;
 507         case FORMAT_LONG:
 508                 prefixLen = snprintf(prefixBuf, sizeof(prefixBuf),
 509                                 "[ %s.%03ld %5d:%5d %c/%-8s ]\n",
 510                                 timeBuf, entry->tv_nsec / 1000000, (int)entry->pid,
 511                                 (int)entry->tid, priChar, entry->tag);
 512                 strcpy(suffixBuf, "\n\n");
 513                 suffixLen = 2;
 514                 prefixSuffixIsHeaderFooter = 1;
 515                 break;
 516         case FORMAT_BRIEF:
 517         default:
 518                 prefixLen = snprintf(prefixBuf, sizeof(prefixBuf),
 519                                 "%c/%-8s(%5d): ", priChar, entry->tag, (int)entry->pid);
 520                 strcpy(suffixBuf, "\n");
 521                 suffixLen = 1;
 522                 break;
 523         }
 524         /* snprintf has a weird return value.   It returns what would have been
 525          * written given a large enough buffer.  In the case that the prefix is
 526          * longer then our buffer(128), it messes up the calculations below
 527          * possibly causing heap corruption.  To avoid this we double check and
 528          * set the length at the maximum (size minus null byte)
 529          */
 530         if(prefixLen >= sizeof(prefixBuf))
 531                 prefixLen = sizeof(prefixBuf) - 1;
 532         if(suffixLen >= sizeof(suffixBuf))
 533                 suffixLen = sizeof(suffixBuf) - 1;
 534
 535         /* the following code is tragically unreadable */
 536
 537         size_t numLines;
 538         char *p;
 539         size_t bufferSize;
 540         const char *pm;
 541
 542         if (prefixSuffixIsHeaderFooter) {
 543                 /* we're just wrapping message with a header/footer */
 544                 numLines = 1;
 545         } else {
 546                 pm = entry->message;
 547                 numLines = 0;
 548
 549                 /* The line-end finding here must match the line-end finding
 550                  * in for ( ... numLines...) loop below
 551                  */
 552                 while (pm < (entry->message + entry->messageLen)) {
 553                         if (*pm++ == '\n') numLines++;
 554                 }
 555                 /* plus one line for anything not newline-terminated at the end */
 556                 if (pm > entry->message && *(pm-1) != '\n') numLines++;
 557         }
 558
 559         /* this is an upper bound--newlines in message may be counted
 560          * extraneously
 561          */
 562         bufferSize = (numLines * (prefixLen + suffixLen)) + entry->messageLen + 1;
 563
 564         if (defaultBufferSize >= bufferSize) {
 565                 ret = defaultBuffer;
 566         } else {
 567                 ret = (char *)malloc(bufferSize);
 568
 569                 if (ret == NULL) {
 570                         return ret;
 571                 }
 572         }
 573
 574         ret[0] = '\0';       /* to start strcat off */
 575
 576         p = ret;
 577         pm = entry->message;
 578
 579         if (prefixSuffixIsHeaderFooter) {
 580                 strcat(p, prefixBuf);
 581                 p += prefixLen;
 582                 strncat(p, entry->message, entry->messageLen);
 583                 p += entry->messageLen;
 584                 strcat(p, suffixBuf);
 585                 p += suffixLen;
 586         } else {
 587                 while (pm < (entry->message + entry->messageLen)) {
 588                         const char *lineStart;
 589                         size_t lineLen;
 590
 591                         lineStart = pm;
 592
 593                         /* Find the next end-of-line in message */
 594                         while (pm < (entry->message + entry->messageLen)
 595                                         && *pm != '\n') pm++;
 596                         lineLen = pm - lineStart;
 597
 598                         strcat(p, prefixBuf);
 599                         p += prefixLen;
 600                         strncat(p, lineStart, lineLen);
 601                         p += lineLen;
 602                         strcat(p, suffixBuf);
 603                         p += suffixLen;
 604
 605                         if (*pm == '\n')
 606                                 pm++;
 607                 }
 608         }
 609
 610         if (p_outLength != NULL) {
 611                 *p_outLength = p - ret;
 612         }
 613
 614         return ret;
 615 }
 616
 617 /**
 618  * Either print or do not print log line, based on filter
 619  *
 620  * Returns count bytes written
 621  */
 622
 623 int log_print_log_line(
 624                 log_format *p_format,
 625                 int fd,
 626                 const log_entry *entry)
 627 {
 628         int ret;
 629         char defaultBuffer[512];
 630         char *outBuffer = NULL;
 631         size_t totalLen;
 632
 633         outBuffer = log_format_log_line(p_format,
 634                         defaultBuffer, sizeof(defaultBuffer), entry, &totalLen);
 635
 636         if (!outBuffer)
 637                 return -1;
 638
 639         do {
 640                 ret = write(fd, outBuffer, totalLen);
 641         } while (ret < 0 && errno == EINTR);
 642
 643         if (ret < 0) {
 644                 fprintf(stderr, "+++ LOG: write failed (errno=%d)\n", errno);
 645                 ret = 0;
 646                 goto done;
 647         }
 648
 649         if (((size_t)ret) < totalLen) {
 650                 fprintf(stderr, "+++ LOG: write partial (%d of %d)\n", ret,
 651                                 (int)totalLen);
 652                 goto done;
 653         }
 654
 655 done:
 656         if (outBuffer != defaultBuffer) {
 657                 free(outBuffer);
 658         }
 659
 660         return ret;
 661 }
 662
 663
 664
 665 void logprint_run_tests()
 666 {
 667         int err;
 668         const char *tag;
 669         log_format *p_format;
 670
 671         p_format = log_format_new();
 672         if (!p_format) {
 673                 fprintf(stderr, "create log_foramt failed\n");
 674                 return;
 675         }
 676
 677         fprintf(stderr, "running tests\n");
 678
 679         tag = "random";
 680
 681         log_add_filter_rule(p_format,"*:i");
 682
 683         assert (DLOG_INFO == filter_pri_for_tag(p_format, "random"));
 684         assert(log_should_print_line(p_format, tag, DLOG_DEBUG) == 0);
 685         log_add_filter_rule(p_format, "*");
 686         assert (DLOG_DEBUG == filter_pri_for_tag(p_format, "random"));
 687         assert(log_should_print_line(p_format, tag, DLOG_DEBUG) > 0);
 688         log_add_filter_rule(p_format, "*:v");
 689         assert (DLOG_VERBOSE == filter_pri_for_tag(p_format, "random"));
 690         assert(log_should_print_line(p_format, tag, DLOG_DEBUG) > 0);
 691         log_add_filter_rule(p_format, "*:i");
 692         assert (DLOG_INFO == filter_pri_for_tag(p_format, "random"));
 693         assert(log_should_print_line(p_format, tag, DLOG_DEBUG) == 0);
 694
 695         log_add_filter_rule(p_format, "random");
 696         assert (DLOG_VERBOSE == filter_pri_for_tag(p_format, "random"));
 697         assert(log_should_print_line(p_format, tag, DLOG_DEBUG) > 0);
 698         log_add_filter_rule(p_format, "random:v");
 699         assert (DLOG_VERBOSE == filter_pri_for_tag(p_format, "random"));
 700         assert(log_should_print_line(p_format, tag, DLOG_DEBUG) > 0);
 701         log_add_filter_rule(p_format, "random:d");
 702         assert (DLOG_DEBUG == filter_pri_for_tag(p_format, "random"));
 703         assert(log_should_print_line(p_format, tag, DLOG_DEBUG) > 0);
 704         log_add_filter_rule(p_format, "random:w");
 705         assert (DLOG_WARN == filter_pri_for_tag(p_format, "random"));
 706         assert(log_should_print_line(p_format, tag, DLOG_DEBUG) == 0);
 707
 708         log_add_filter_rule(p_format, "crap:*");
 709         assert (DLOG_VERBOSE== filter_pri_for_tag(p_format, "crap"));
 710         assert(log_should_print_line(p_format, "crap", DLOG_VERBOSE) > 0);
 711
 712         /* invalid expression */
 713         err = log_add_filter_rule(p_format, "random:z");
 714         assert (err < 0);
 715         assert (DLOG_WARN == filter_pri_for_tag(p_format, "random"));
 716         assert(log_should_print_line(p_format, tag, DLOG_DEBUG) == 0);
 717
 718         /* Issue #550946 */
 719         err = log_add_filter_string(p_format, " ");
 720         assert(err == 0);
 721         assert(DLOG_WARN == filter_pri_for_tag(p_format, "random"));
 722
 723         /* note trailing space */
 724         err = log_add_filter_string(p_format, "*:s random:d ");
 725         assert(err == 0);
 726         assert(DLOG_DEBUG == filter_pri_for_tag(p_format, "random"));
 727
 728         err = log_add_filter_string(p_format, "*:s random:z");
 729         assert(err < 0);
 730
 731         log_format_free(p_format);
 732
 733         fprintf(stderr, "tests complete\n");
 734 }
 735