src/shared/logprint.c

   1 /*
   2  * DLOG
   3  * Copyright (c) 2012-2020 Samsung Electronics Co., Ltd.
   4  *
   5  * Licensed under the Apache License, Version 2.0 (the License);
   6  * you may not use this file except in compliance with the License.
   7  * You may obtain a copy of the License at
   8  *
   9  *     http://www.apache.org/licenses/LICENSE-2.0
  10  *
  11  * Unless required by applicable law or agreed to in writing, software
  12  * distributed under the License is distributed on an "AS IS" BASIS,
  13  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  14  * See the License for the specific language governing permissions and
  15  * limitations under the License.
  16  */
  17
  18 #include <assert.h>
  19 #include <stdbool.h>
  20 #include <stdio.h>
  21 #include <stdlib.h>
  22 #include <ctype.h>
  23 #include <tizen.h>
  24
  25 #include <logprint.h>
  26 #include <logcommon.h>
  27
  28 /**
  29  * @addtogroup SHARED_FUNCTIONS
  30  * @{
  31  */
  32
  33 #define FILTERINFO_PID_NONE -1
  34 #define FILTERINFO_TID_NONE -1
  35
  36 struct dlogutil_filter_options {
  37         list_head filters;
  38         log_priority global_pri;
  39         bool exact_global_pri;
  40         bool need_apply_default;
  41 };
  42
  43 /**
  44  * @brief Allocate filter info
  45  * @details Allocates filter info with given parameters
  46  * @param[in] tag The filtering tag
  47  * @param[in] pri The filtering priority
  48  * @param[in] exactPri The filtering priority is exact
  49  * @param[in] prefix The filtering tag is a prefix
  50  * @return The new structure (or NULL if allocation failed).
  51  * @see filterinfo_free
  52  */
  53 static FilterInfo *filterinfo_new(const char *tag, log_priority pri, bool prefix, bool exactPri, pid_t pid, pthread_t tid)
  54 {
  55         FilterInfo *p_ret = (FilterInfo *)calloc(1, sizeof(FilterInfo));
  56         if (!p_ret)
  57                 return NULL;
  58
  59         if (tag) {
  60                 p_ret->type = FILTER_TAG_AND_PRIO;
  61                 p_ret->tnp.tag = strdup(tag);
  62                 if (!p_ret->tnp.tag) {
  63                         free(p_ret);
  64                         return NULL;
  65                 }
  66                 p_ret->tnp.tagLength = strlen(p_ret->tnp.tag);
  67                 p_ret->tnp.pri = pri;
  68                 p_ret->tnp.exactPri = exactPri;
  69                 p_ret->tnp.prefix = prefix;
  70         } else if (pid != FILTERINFO_PID_NONE) {
  71                 p_ret->type = FILTER_PID;
  72                 p_ret->pid = pid;
  73         } else if (tid != FILTERINFO_TID_NONE) {
  74                 p_ret->type = FILTER_TID;
  75                 p_ret->tid = tid;
  76         } else {
  77                 assert(false); // LCOV_EXCL_LINE
  78         }
  79
  80         return p_ret;
  81 }
  82
  83 static FilterInfo *filterinfo_clone(FilterInfo *p_info)
  84 {
  85         assert(p_info);
  86
  87         switch (p_info->type) {
  88         case FILTER_TAG_AND_PRIO:
  89                 return filterinfo_new(p_info->tnp.tag, p_info->tnp.pri, p_info->tnp.prefix, p_info->tnp.exactPri, FILTERINFO_PID_NONE, FILTERINFO_TID_NONE);
  90         case FILTER_PID:
  91                 return filterinfo_new(NULL, 0, false, false, p_info->pid, FILTERINFO_TID_NONE);
  92         case FILTER_TID:
  93                 return filterinfo_new(NULL, 0, false, false, FILTERINFO_PID_NONE, p_info->tid);
  94
  95         default: assert(false); // LCOV_EXCL_LINE
  96         }
  97 }
  98
  99 /**
 100  * @brief Deallocate filter info
 101  * @details Deallocates the entire filter info structure
 102  * @param[in] p_info The structure to deallocate
 103  * @see filterinfo_new
 104  */
 105 static void filterinfo_free(FilterInfo *p_info)
 106 {
 107         assert(p_info);
 108
 109         if (p_info->type == FILTER_TAG_AND_PRIO) {
 110                 free(p_info->tnp.tag);
 111                 p_info->tnp.tag = NULL;
 112         }
 113
 114         free(p_info);
 115 }
 116
 117 // apply_cb versions of two previous functions
 118 elem_value filterinfo_clone_cb(elem_value p_info, void *_)
 119 {
 120         return filterinfo_clone(p_info);
 121 }
 122 static void filterinfo_free_cb(elem_value p_info, void *_)
 123 {
 124         filterinfo_free(p_info);
 125 }
 126
 127 #define DLOG_ERROR_NOTAG "DLOG_ERROR_NOTAG"
 128
 129 /**
 130  * @brief Filter a line
 131  * @details Passes a line through filters to discover whether it should be logged or not
 132  * @param[in] p_format The format to work with
 133  * @param[in] entry The log entry to filter
 134  * @return True if the line should be printed, else false
 135  */
 136 bool log_should_print_line(dlogutil_filter_options_s *p_filter, const dlogutil_entry_s *entry)
 137 {
 138         assert(p_filter);
 139         assert(entry);
 140
 141         bool prefix;
 142         bool matched = false;
 143         const char *tag;
 144         log_priority prio;
 145
 146         /* mark empty-tagged messages and make it easy to catch an application that does that */
 147         if (dlogutil_entry_get_tag(entry, &tag) == TIZEN_ERROR_NO_DATA || !tag || !strlen(tag))
 148                 tag = DLOG_ERROR_NOTAG;
 149
 150         prio = (log_priority)entry->priority;
 151
 152         // Sadly, we can't use list_foreach, because it doesn't let us exit early
 153         for (list_head p_curFilter_iter = p_filter->filters; p_curFilter_iter != NULL; list_next(&p_curFilter_iter)) {
 154                 FilterInfo *p_curFilter = list_at(p_curFilter_iter);
 155
 156                 switch (p_curFilter->type) {
 157                 case FILTER_TAG_AND_PRIO:
 158                         prefix = p_curFilter->tnp.prefix;
 159                         if ((prefix && (0 == strncmp(tag, p_curFilter->tnp.tag, p_curFilter->tnp.tagLength))) ||
 160                             (!prefix && (0 == strcmp(tag, p_curFilter->tnp.tag)))) {
 161                                 matched = true;
 162                                 if (p_curFilter->tnp.exactPri) {
 163                                         if (prio == p_curFilter->tnp.pri)
 164                                                 return true;
 165                                 } else {
 166                                         if (prio >= p_curFilter->tnp.pri)
 167                                                 return true;
 168                                 }
 169                         }
 170                         break;
 171                 case FILTER_PID:
 172                         matched = true;
 173                         if (entry->pid == p_curFilter->pid)
 174                                 return true;
 175                         break;
 176                 case FILTER_TID:
 177                         matched = true;
 178                         if (entry->tid == p_curFilter->tid)
 179                                 return true;
 180                         break;
 181
 182                 default: assert(false); // LCOV_EXCL_LINE
 183                 }
 184
 185         }
 186         if (matched)
 187                 return false;
 188
 189         if (p_filter->exact_global_pri)
 190                 return (prio == p_filter->global_pri);
 191         else
 192                 return (prio >= p_filter->global_pri);
 193 }
 194
 195 bool log_filter_need_apply_default(dlogutil_filter_options_s *p_filter)
 196 {
 197         assert(p_filter);
 198         return p_filter->need_apply_default;
 199 }
 200
 201 /**
 202  * @brief Allocate log format
 203  * @details Allocates a log format structure
 204  * @return The new structure (or NULL if allocation failed).
 205  * @see log_filter_free
 206  */
 207 dlogutil_filter_options_s *log_filter_new(void)
 208 {
 209         dlogutil_filter_options_s *p_ret;
 210
 211         p_ret = calloc(1, sizeof(dlogutil_filter_options_s));
 212
 213         if (!p_ret)
 214                 return NULL;
 215         p_ret->global_pri = DLOG_SILENT;
 216         p_ret->exact_global_pri = false;
 217         p_ret->need_apply_default = true;
 218
 219         return p_ret;
 220 }
 221
 222 /**
 223  * @brief Copy a log format
 224  * @details Allocates a copy of the log format
 225  * @param[in] p_format The log format to copy
 226  * @return The new structure (or NULL if allocation failed)
 227  * @see log_filter_free
 228  */
 229 dlogutil_filter_options_s *log_filter_from_filter(const dlogutil_filter_options_s *p_filter)
 230 {
 231         dlogutil_filter_options_s *p_ret;
 232
 233         if (!(p_ret = log_filter_new()))
 234                 return NULL;
 235
 236         p_ret->global_pri = p_filter->global_pri;
 237         p_ret->exact_global_pri = p_filter->exact_global_pri;
 238         p_ret->need_apply_default = p_filter->need_apply_default;
 239
 240         if (p_filter->filters) {
 241                 p_ret->filters = list_map(p_filter->filters, NULL, filterinfo_clone_cb, filterinfo_free_cb);
 242
 243                 if (!p_ret->filters)
 244                 {
 245                         log_filter_free(p_ret);
 246                         return NULL;
 247                 }
 248         }
 249
 250         return p_ret;
 251 }
 252
 253 /**
 254  * @brief Move a log format
 255  * @details Moves a log format (like C++ std::move)
 256  * @param[in] p_format The log format to move
 257  * @return The new structure (or NULL if allocation failed)
 258  * @see log_filter_free
 259  */
 260 dlogutil_filter_options_s *log_filter_move(dlogutil_filter_options_s *p_filter)
 261 {
 262         dlogutil_filter_options_s *const ret = malloc(sizeof *ret);
 263         if (!ret)
 264                 return NULL;
 265
 266         *ret = *p_filter;
 267         p_filter->filters = NULL;
 268
 269         return ret;
 270 }
 271
 272 /**
 273  * @brief Deallocate log format
 274  * @details Deallocates the entire log format structure
 275  * @param[in] p_format The structure to deallocate
 276  */
 277 void log_filter_free(dlogutil_filter_options_s *p_filter)
 278 {
 279         if (p_filter) {
 280                 log_filter_clear(p_filter);
 281
 282                 free(p_filter);
 283         }
 284 }
 285
 286 void log_filter_clear(dlogutil_filter_options_s *p_filter)
 287 {
 288         assert(p_filter);
 289
 290         list_clear_custom(&p_filter->filters, NULL, filterinfo_free_cb);
 291         p_filter->global_pri = DLOG_SILENT;
 292         p_filter->exact_global_pri = false;
 293 }
 294
 295 list_head log_filter_get_list(dlogutil_filter_options_s *p_filter)
 296 {
 297         assert(p_filter);
 298
 299         return p_filter->filters;
 300 }
 301
 302 log_priority log_filter_get_global_priority(dlogutil_filter_options_s *p_filter, bool *is_exact)
 303 {
 304         assert(is_exact);
 305         assert(p_filter);
 306
 307         *is_exact = p_filter->exact_global_pri;
 308         return p_filter->global_pri;
 309 }
 310
 311 /**
 312  * @brief Print format from string
 313  * @details Converts a string to print format
 314  * @param[in] formatString The string representation to convert
 315  * @return The integer print format (on invalid string: FORMAT_OFF)
 316  */
 317 log_print_format log_format_from_string(const char *formatString)
 318 {
 319         static const struct {
 320                 char const *string;
 321                 log_print_format format;
 322         } formats[] = {
 323                 {"brief"        , FORMAT_BRIEF        },
 324                 {"process"      , FORMAT_PROCESS      },
 325                 {"tag"          , FORMAT_TAG          },
 326                 {"thread"       , FORMAT_THREAD       },
 327                 {"raw"          , FORMAT_RAW          },
 328                 {"time"         , FORMAT_TIME         },
 329                 {"threadtime"   , FORMAT_THREADTIME   },
 330                 {"kerneltime"   , FORMAT_KERNELTIME   },
 331                 {"recv_realtime", FORMAT_RECV_REALTIME},
 332                 {"rwtime"       , FORMAT_RWTIME       },
 333                 {"long"         , FORMAT_LONG         },
 334                 {"json"         , FORMAT_JSON         },
 335         };
 336
 337         for (size_t i = 0; i < NELEMS(formats); ++i)
 338                 if (!strcmp(formatString, formats[i].string))
 339                         return formats[i].format;
 340
 341         return FORMAT_OFF;
 342 }
 343
 344 /**
 345  * @brief Add a filter rule
 346  * @details Adds a tag/priority filtering rule
 347  * @param[in] p_format The log format to add the filter rule to
 348  * @param[in] filterExpression A filter expression ("tag:prio")
 349  * @return An error code
 350  * @retval TIZEN_ERROR_NONE Success
 351  * @retval TIZEN_ERROR_INVALID_PARAMETER Invalid syntax of the filterspec
 352  * @retval TIZEN_ERROR_OUT_OF_MEMORY Couldn't allocate enough memory
 353  * @remarks Assumes single threaded execution
 354  */
 355 int log_add_filter_rule(dlogutil_filter_options_s *p_filter,
 356                 const char *filterExpression)
 357 {
 358         size_t tagNameLength, priPosition;
 359         bool exact = false;
 360         bool pattern = false;
 361         log_priority pri = DLOG_DEFAULT;
 362
 363         tagNameLength = strcspn(filterExpression, ":");
 364
 365         if (tagNameLength == 0)
 366                 return TIZEN_ERROR_INVALID_PARAMETER;
 367
 368         if (filterExpression[tagNameLength] == ':') {
 369                 if ((strlen(filterExpression + (tagNameLength + 1)) > 1)
 370                         && (filterExpression[tagNameLength + 1] == '=')) {
 371                         priPosition = tagNameLength + 2;
 372                         exact = true;
 373                 } else {
 374                         priPosition = tagNameLength + 1;
 375                         exact = false;
 376                 }
 377                 pri = filter_char_to_pri(filterExpression[priPosition]);
 378
 379                 if (pri == DLOG_UNKNOWN)
 380                         return TIZEN_ERROR_INVALID_PARAMETER;
 381         }
 382
 383         if (0 == strncmp("*", filterExpression, tagNameLength)) {
 384                 /* This filter expression refers to the global filter
 385                  * The default level for this is DEBUG if the priority
 386                  * is unspecified
 387                  */
 388                 if (pri == DLOG_DEFAULT)
 389                         pri = DLOG_DEBUG;
 390
 391                 p_filter->global_pri = pri;
 392                 p_filter->exact_global_pri = exact;
 393         } else {
 394                 /* for filter expressions that don't refer to the global
 395                  * filter, the default is verbose if the priority is unspecified
 396                  */
 397                 if (pri == DLOG_DEFAULT)
 398                         pri = DLOG_VERBOSE;
 399
 400                 if (filterExpression[tagNameLength - 1] == '*') {
 401                         pattern = true;
 402                         tagNameLength = tagNameLength - 1;
 403                 } else
 404                         pattern = false;
 405
 406                 char *tagName = strndup(filterExpression, tagNameLength);
 407                 if (!tagName)
 408                         return TIZEN_ERROR_OUT_OF_MEMORY;
 409
 410                 FilterInfo *p_fi = filterinfo_new(tagName, pri, pattern, exact, FILTERINFO_PID_NONE, FILTERINFO_TID_NONE);
 411                 free(tagName);
 412                 if (!p_fi)
 413                         return TIZEN_ERROR_OUT_OF_MEMORY;
 414
 415                 if (!list_add(&p_filter->filters, p_fi))
 416                         return TIZEN_ERROR_OUT_OF_MEMORY;
 417         }
 418
 419         return TIZEN_ERROR_NONE;
 420 }
 421
 422 /**
 423  * @brief Add filter string
 424  * @details Adds multiple tag/priority filtering rule from a string
 425  * @param[in] p_format The log format to add the filter rules to
 426  * @param[in] filterString A filter string containing multiple filter rules delimited by spaces, tabs or commas
 427  * @return An error code
 428  * @retval TIZEN_ERROR_NONE Success
 429  * @retval TIZEN_ERROR_INVALID_PARAMETER Invalid syntax of the filterspec
 430  * @retval TIZEN_ERROR_INVALID_PARAMETER One of the pointers was NULL
 431  * @retval TIZEN_ERROR_OUT_OF_MEMORY Couldn't allocate enough memory
 432  * @remarks Assumes single threaded execution
 433  */
 434 LIBDLOGUTIL_EXPORT_API int dlogutil_filter_options_set_filterspec(dlogutil_filter_options_s *p_filter,
 435                 const char *filterString)
 436 {
 437         CHECK_PARAM(p_filter);
 438         CHECK_PARAM(filterString);
 439
 440         char *filterStringCopy = strdup(filterString);
 441         if (!filterStringCopy)
 442                 return TIZEN_ERROR_OUT_OF_MEMORY;
 443
 444         char *p_cur = filterStringCopy;
 445         char *p_ret;
 446         int err;
 447
 448         while (NULL != (p_ret = strsep(&p_cur, " \t,"))) {
 449                 /* ignore whitespace-only entries */
 450                 if (p_ret[0] != '\0') {
 451                         err = log_add_filter_rule(p_filter, p_ret);
 452
 453                         if (err < 0) {
 454                                 free(filterStringCopy);
 455                                 return err;
 456                         }
 457                 }
 458         }
 459
 460         p_filter->need_apply_default = false;
 461
 462         free(filterStringCopy);
 463         return TIZEN_ERROR_NONE;
 464 }
 465
 466 /**
 467  * @brief Add pid to filter by
 468  * @details Adds a single pid filtering rule
 469  * @param[in] p_format The log format to add the filter rules to
 470  * @param[in] pid A pid to filter by
 471  * @return An error code
 472  * @retval TIZEN_ERROR_NONE Success
 473  * @retval TIZEN_ERROR_INVALID_PARAMETER One of the pointers was NULL
 474  * @retval TIZEN_ERROR_OUT_OF_MEMORY Couldn't allocate enough memory
 475  * @remarks Assumes single threaded execution
 476  */
 477 LIBDLOGUTIL_EXPORT_API int dlogutil_filter_options_set_pid(dlogutil_filter_options_s *p_filter, pid_t pid)
 478 {
 479         CHECK_PARAM(p_filter);
 480
 481         FilterInfo *p_fi = filterinfo_new(NULL, 0, false, false, pid, FILTERINFO_TID_NONE);
 482         if (!p_fi)
 483                 return TIZEN_ERROR_OUT_OF_MEMORY;
 484
 485         return list_add(&p_filter->filters, p_fi) ? TIZEN_ERROR_NONE : TIZEN_ERROR_OUT_OF_MEMORY;
 486 }
 487
 488 /**
 489  * @brief Add tid to filter by
 490  * @details Adds a single tid filtering rule
 491  * @param[in] p_format The log format to add the filter rules to
 492  * @param[in] tid A tid to filter by
 493  * @return An error code
 494  * @retval TIZEN_ERROR_NONE Success
 495  * @retval TIZEN_ERROR_INVALID_PARAMETER One of the pointers was NULL
 496  * @retval TIZEN_ERROR_OUT_OF_MEMORY Couldn't allocate enough memory
 497  * @remarks Assumes single threaded execution
 498  */
 499 LIBDLOGUTIL_EXPORT_API int dlogutil_filter_options_set_tid(dlogutil_filter_options_s *p_filter, pid_t tid)
 500 {
 501         CHECK_PARAM(p_filter);
 502
 503         FilterInfo *p_fi = filterinfo_new(NULL, 0, false, false, FILTERINFO_PID_NONE, tid);
 504         if (!p_fi)
 505                 return TIZEN_ERROR_OUT_OF_MEMORY;
 506
 507         return list_add(&p_filter->filters, p_fi) ? TIZEN_ERROR_NONE : TIZEN_ERROR_OUT_OF_MEMORY;
 508 }
 509
 510 dlogutil_sorting_order_e get_format_sorting(log_print_format format)
 511 {
 512         switch (format) {
 513         case FORMAT_TAG:
 514         case FORMAT_PROCESS:
 515         case FORMAT_THREAD:
 516         case FORMAT_RAW:
 517         case FORMAT_BRIEF:
 518         case FORMAT_JSON:
 519                 return DLOGUTIL_SORT_DEFAULT;
 520
 521         case FORMAT_KERNELTIME:
 522                 return DLOGUTIL_SORT_SENT_MONO;
 523
 524         case FORMAT_TIME:
 525         case FORMAT_THREADTIME:
 526         case FORMAT_LONG:
 527                 return DLOGUTIL_SORT_SENT_REAL;
 528
 529         case FORMAT_RWTIME:
 530         case FORMAT_RECV_REALTIME:
 531                 return DLOGUTIL_SORT_RECV_REAL;
 532
 533         default: assert(false); // LCOV_EXCL_LINE
 534         }
 535 }
 536
 537 #define COLOR_PURPLE "\033[35;1m"
 538 #define COLOR_RED    "\033[31;1m"
 539 #define COLOR_YELLOW "\033[33;1m"
 540 #define COLOR_RESET  "\033[0m"
 541
 542 static const char *get_pre_color(log_priority pri)
 543 {
 544         switch (pri) {
 545         case DLOG_FATAL:
 546                 return COLOR_PURPLE;
 547         case DLOG_ERROR:
 548                 return COLOR_RED;
 549         case DLOG_WARN:
 550                 return COLOR_YELLOW;
 551         default:
 552                 return "";
 553         }
 554 }
 555
 556 static const char *get_post_color(log_priority pri)
 557 {
 558         switch (pri) {
 559         case DLOG_FATAL:
 560         case DLOG_ERROR:
 561         case DLOG_WARN:
 562                 return COLOR_RESET;
 563         default:
 564                 return "";
 565         }
 566 }
 567
 568 static char to_hex_digit(int digit)
 569 {
 570         assert(digit >= 0);
 571         assert(digit < 16);
 572         if (digit < 10)
 573                 return digit + '0';
 574         else
 575                 return digit + 'A' - 10;
 576 }
 577
 578 char *json_escape_string(const char *in)
 579 {
 580         assert(in);
 581         size_t len = strlen(in);
 582         /* One input string character will be encoded by max 6 characters in the output string.
 583          * We use unsigned chars for easy comparisions. */
 584         unsigned char *buf = malloc(6 * len + 1);
 585         if (!buf)
 586                 return NULL;
 587
 588         /* So, RFC 7159 says that JSON output can be in one of three encodings: UTF-{8,16,32}.
 589          * In particular, in UTF-8, the multibyte characters are allowed. This means that, assuming
 590          * that our input is valid UTF-8, we can just write them directly, simplifying the implementation.
 591          * Correctly encoding arbitrary binary data would require something like base64, this, however,
 592          * would make it very difficult to read by humans. Almost all logs are UTF-8 anyway. */
 593         int targ = 0;
 594         for (size_t i = 0; i < len; ++i) {
 595                 unsigned char c = in[i];
 596                 switch (c) {
 597                 /* These cases can get nicer encodings than the usual "\uxxxx", even though we technically
 598                  * dont have to do so. Also, we don't encode '/', because there is no reason to. */
 599                 case '\"':
 600                         buf[targ++] = '\\';
 601                         buf[targ++] = '\"';
 602                         break;
 603                 case '\\':
 604                         buf[targ++] = '\\';
 605                         buf[targ++] = '\\';
 606                         break;
 607                 case '\b':
 608                         buf[targ++] = '\\';
 609                         buf[targ++] = 'b';
 610                         break;
 611                 case '\f':
 612                         buf[targ++] = '\\';
 613                         buf[targ++] = 'f';
 614                         break;
 615                 case '\n':
 616                         buf[targ++] = '\\';
 617                         buf[targ++] = 'n';
 618                         break;
 619                 case '\r':
 620                         buf[targ++] = '\\';
 621                         buf[targ++] = 'r';
 622                         break;
 623                 case '\t':
 624                         buf[targ++] = '\\';
 625                         buf[targ++] = 't';
 626                         break;
 627                 default:
 628                         /* We don't use a range case, because we would have to remove the already done characters from it.
 629                          * We would end up with three distinct cases for the {0, ..., 31} interval. */
 630                         if (c <= 31) {
 631                                 buf[targ++] = '\\';
 632                                 buf[targ++] = 'u';
 633                                 buf[targ++] = '0';
 634                                 buf[targ++] = '0';
 635                                 buf[targ++] = to_hex_digit(c / 16);
 636                                 buf[targ++] = to_hex_digit(c % 16);
 637                         }
 638                         else
 639                                 buf[targ++] = c;
 640                         break;
 641                 }
 642         }
 643         buf[targ++] = '\0';
 644
 645         char *ret = realloc(buf, targ);
 646         if (!ret)
 647                 free(buf);
 648         return ret;
 649 }
 650
 651 const char *json_priority_name(log_priority prio)
 652 {
 653         static const char *const json_priorities_map[] = {
 654                 [DLOG_VERBOSE] = "verbose",
 655                 [DLOG_DEBUG]   = "debug",
 656                 [DLOG_INFO]    = "info",
 657                 [DLOG_WARN]    = "warning",
 658                 [DLOG_ERROR]   = "error",
 659                 [DLOG_FATAL]   = "fatal",
 660                 [DLOG_SILENT]  = "silent",
 661         };
 662
 663         const char *ret = NULL;
 664         if (prio < NELEMS(json_priorities_map))
 665                 ret = json_priorities_map[prio];
 666         if (!ret) // Either out of the map, or in between its elements
 667                 ret = "unknown";
 668         return ret;
 669 }
 670
 671 char *log_format_json(
 672                 char *default_buffer,
 673                 size_t default_buffer_size,
 674                 const dlogutil_entry_s *entry,
 675                 size_t *p_outLength,
 676                 const char *tag,
 677                 const char *msg)
 678 {
 679         const char *prio_name = json_priority_name(entry->priority);
 680
 681         __attribute__((cleanup(free_ptr))) char *tag_esc = json_escape_string(tag);
 682         if (tag_esc == NULL)
 683                 return NULL;
 684
 685         __attribute__((cleanup(free_ptr))) char *msg_esc = json_escape_string(msg);
 686         if (msg_esc == NULL)
 687                 return NULL;
 688
 689         char recv_real[64], recv_mono[64], sent_real[64], sent_mono[64];
 690         struct tm tmBuf;
 691         struct tm* ptm;
 692         time_t time_t_temp;
 693
 694         if (entry->nsec_recv_real == INVALID_NSEC)
 695                 recv_real[0] = '\0';
 696         else {
 697                 time_t_temp = entry->sec_recv_real;
 698                 ptm = localtime_r(&time_t_temp, &tmBuf);
 699                 if (!ptm)
 700                         return NULL;
 701                 strftime(recv_real, sizeof recv_real, "\"recv_real\":\"%FT%T%z\",", ptm);
 702         }
 703
 704         if (entry->nsec_sent_real == INVALID_NSEC)
 705                 sent_real[0] = '\0';
 706         else {
 707                 time_t_temp = entry->sec_sent_real;
 708                 ptm = localtime_r(&time_t_temp, &tmBuf);
 709                 if (!ptm)
 710                         return NULL;
 711                 strftime(sent_real, sizeof sent_real, "\"sent_real\":\"%FT%T%z\",", ptm);
 712         }
 713
 714         if (entry->nsec_recv_mono == INVALID_NSEC)
 715                 recv_mono[0] = '\0';
 716         else
 717                 snprintf(recv_mono, sizeof recv_mono, "\"recv_mono\":%d.%.9d,", entry->sec_recv_mono, entry->nsec_recv_mono);
 718
 719         if (entry->nsec_sent_mono == INVALID_NSEC)
 720                 sent_mono[0] = '\0';
 721         else
 722                 snprintf(sent_mono, sizeof sent_mono, "\"sent_mono\":%d.%.9d,", entry->sec_sent_mono, entry->nsec_sent_mono);
 723
 724 #define ARGS "{" \
 725                 "\"priority\":\"%s\"," \
 726                 "\"pid\":%d," \
 727                 "\"tid\":%d," \
 728                 "%s%s%s%s" \
 729                 "\"tag\":\"%s\"," \
 730                 "\"msg\":\"%s\"" \
 731                 "}\n", prio_name, entry->pid, entry->tid, \
 732                 recv_real, recv_mono, sent_real, sent_mono, \
 733                 tag_esc, msg_esc
 734
 735         int len = snprintf(NULL, 0, ARGS);
 736
 737         char *ret;
 738         if (len < 0)
 739                 return NULL;
 740         else if (default_buffer_size >= len + 1) {
 741                 ret = default_buffer;
 742         } else {
 743                 ret = (char *)malloc(len + 1);
 744
 745                 if (ret == NULL)
 746                         return NULL;
 747         }
 748
 749         int res = snprintf(ret, len + 1, ARGS);
 750
 751 #undef ARGS
 752
 753         if (res <= 0) {
 754                 if (ret != default_buffer)
 755                         free(ret);
 756                 return NULL;
 757         }
 758
 759         *p_outLength = len;
 760         return ret;
 761 }
 762
 763 static bool entry_get_ts_inner(const dlogutil_entry_s *entry, bool sent, bool mono, struct timespec *target)
 764 {
 765         int sec = sent
 766                 ? (mono ? entry->sec_sent_mono : entry->sec_sent_real)
 767                 : (mono ? entry->sec_recv_mono : entry->sec_recv_real);
 768         int nsec = sent
 769                 ? (mono ? entry->nsec_sent_mono : entry->nsec_sent_real)
 770                 : (mono ? entry->nsec_recv_mono : entry->nsec_recv_real);
 771
 772         if (nsec == INVALID_NSEC)
 773                 return false;
 774
 775         target->tv_sec = sec;
 776         target->tv_nsec = nsec;
 777         return true;
 778 }
 779
 780 struct timespec entry_get_ts(const dlogutil_entry_s *entry, bool sent, bool mono)
 781 {
 782         /* The returned timestamp should match the format (as in, the printf specifier) used below.
 783          * In particular, monotonic timestamps should be the ones represented by the 'raw' (%u)
 784          * format (currently used solely by the KERNELTIME format) while realtime timestamps should
 785          * be represented by strftime date-formatted strings.
 786          * However, we decided that some timing data is better than none. Therefore, if the needed timestamp
 787          * is missing, we use one of the others, even though it probably is at least slightly wrong.
 788          * A better solution will be possible after the planned refactor of the format system.
 789          * In particular, we allow using the realtime stamp in the monotonic field, as well as using sending
 790          * and receiving timestamps interchangeably. */
 791
 792         struct timespec ret = {0};
 793
 794 #define CHECK_AND_CHANGE_SENT \
 795                 if (entry_get_ts_inner(entry, sent, mono, &ret)) \
 796                         return ret; \
 797                 sent = !sent;
 798
 799         CHECK_AND_CHANGE_SENT
 800         CHECK_AND_CHANGE_SENT
 801
 802         if (mono) {
 803                 mono = false;
 804                 CHECK_AND_CHANGE_SENT
 805                 CHECK_AND_CHANGE_SENT
 806         }
 807
 808 #undef CHECK_AND_CHANGE_SENT
 809
 810         return ret;
 811 }
 812
 813 static int resolve_write(int fd, struct log_write_buffer *wrbuf, const char *realbuf, size_t realsize)
 814 {
 815         if (realbuf != wrbuf->data + wrbuf->position) {
 816                 if (wrbuf->position > 0) {
 817                         int res = write(fd, wrbuf->data, wrbuf->position);
 818                         if (res <= 0)
 819                                 return 0;
 820                 }
 821
 822                 int res;
 823                 if (realsize < wrbuf->size) {
 824                         memcpy(wrbuf->data, realbuf, realsize);
 825                         clock_gettime(CLOCK_MONOTONIC, &wrbuf->oldest_log);
 826                         res = wrbuf->position = realsize;
 827                 } else {
 828                         res = write(fd, realbuf, realsize);
 829                         wrbuf->position = 0;
 830                 }
 831                 return res > 0 ? res : 0;
 832         } else {
 833                 if (wrbuf->position == 0)
 834                         clock_gettime(CLOCK_MONOTONIC, &wrbuf->oldest_log);
 835                 wrbuf->position += realsize;
 836                 return realsize;
 837         }
 838 }
 839
 840 static int log_print_line_format_json(int fd, const dlogutil_entry_s *entry, struct log_write_buffer *wrbuf)
 841 {
 842         size_t buflen;
 843         // TODO: This could really use an improvement
 844         char *const buf = log_format_json(wrbuf->data + wrbuf->position, wrbuf->size - wrbuf->position, entry, &buflen, entry->msg, entry->msg + entry->tag_len + 1);
 845         if (!buf)
 846                 return -1;
 847         bool to_free = buf != (wrbuf->data + wrbuf->position);
 848
 849         int res = resolve_write(fd, wrbuf, buf, buflen);
 850         if (to_free)
 851                 free(buf);
 852         return res;
 853 }
 854
 855 #define METADATA_MAX_LEN 128
 856 #define COLORED_METADATA_MAX_LEN (METADATA_MAX_LEN  + sizeof COLOR_PURPLE + sizeof COLOR_RESET)
 857
 858 #define FORMAT_STR_PRIORITY "%c"
 859 #define FORMAT_STR_TAG "%s"
 860 #define FORMAT_STR_PID "%5u"
 861 #define FORMAT_STR_TID "%5u"
 862 #define FORMAT_STR_KERNELTIME "%05ld.%03ld"
 863
 864 #define MILISEC_SIZE (sizeof(".012")-1)
 865 #define NSEC_TO_MSEC(t) ((t) / 1000000)
 866
 867 static void buf_add_milisec(char *buf, int32_t nsec)
 868 {
 869         *(buf++) = '.';
 870         snprintf(buf, MILISEC_SIZE, "%03d", NSEC_TO_MSEC(nsec));
 871 }
 872
 873 static char *buf_add_time(char *buf, size_t max_len, const dlogutil_entry_s *entry,
 874                                                   bool add_ms, bool add_tz, bool sent_time)
 875 {
 876         struct tm tmBuf;
 877         struct timespec t = entry_get_ts(entry, sent_time, false);
 878         struct tm *const ptm = localtime_r(&t.tv_sec, &tmBuf);
 879         if (!ptm)
 880                 return NULL;
 881
 882         size_t written = strftime(buf, max_len, "%m-%d %H:%M:%S", ptm);
 883
 884         if (add_ms && max_len - written > MILISEC_SIZE) {
 885                 buf_add_milisec(buf + written, t.tv_nsec);
 886                 written += MILISEC_SIZE; // not counting terminating null byte
 887         }
 888
 889         if (add_tz && sent_time)
 890                 written += strftime(buf + written, max_len - written, "%z", ptm);
 891
 892         return buf + written;
 893 }
 894
 895 static char entry_get_priority_string(const dlogutil_entry_s *entry)
 896 {
 897         return filter_pri_to_char(entry->priority);
 898 }
 899
 900 static const char *entry_get_tag_string(const dlogutil_entry_s *entry)
 901 {
 902         const char *ret;
 903         int r = dlogutil_entry_get_tag(entry, &ret);
 904         if (r == TIZEN_ERROR_NO_DATA || strlen(ret) == 0)
 905                 return DLOG_ERROR_NOTAG;
 906
 907         return ret;
 908 }
 909
 910 static const char *entry_get_message_string(const dlogutil_entry_s *entry)
 911 {
 912         const char *ret;
 913         int r = dlogutil_entry_get_message(entry, &ret);
 914         if (r == TIZEN_ERROR_NO_DATA || strlen(ret) == 0)
 915                 return "DLOG_ERROR_NOMSG";
 916
 917         return ret;
 918 }
 919
 920 typedef int (*format_function)(const dlogutil_entry_s *, char *, char *);
 921
 922 static int format_metadata_brief(const dlogutil_entry_s *entry, char *prefix, char *suffix)
 923 {
 924         snprintf(prefix, METADATA_MAX_LEN,
 925                          FORMAT_STR_PRIORITY "/" FORMAT_STR_TAG "(" FORMAT_STR_PID "): ",
 926                          entry_get_priority_string(entry),
 927                          entry_get_tag_string(entry),
 928                          entry->pid);
 929         return 0;
 930 }
 931
 932 static int format_metadata_process(const dlogutil_entry_s *entry, char *prefix, char *suffix)
 933 {
 934         snprintf(prefix, METADATA_MAX_LEN,
 935                          FORMAT_STR_PRIORITY "(" FORMAT_STR_PID ") ",
 936                          entry_get_priority_string(entry),
 937                          entry->pid);
 938
 939         snprintf(suffix, METADATA_MAX_LEN,
 940                          "  (" FORMAT_STR_TAG ")\n",
 941                          entry_get_tag_string(entry));
 942         return 0;
 943 }
 944
 945 static int format_metadata_tag(const dlogutil_entry_s *entry, char *prefix, char *suffix)
 946 {
 947         snprintf(prefix, METADATA_MAX_LEN,
 948                          FORMAT_STR_PRIORITY "/" FORMAT_STR_TAG ": ",
 949                          entry_get_priority_string(entry),
 950                          entry_get_tag_string(entry));
 951         return 0;
 952 }
 953
 954 static int format_metadata_thread(const dlogutil_entry_s *entry, char *prefix, char *suffix)
 955 {
 956         snprintf(prefix, METADATA_MAX_LEN,
 957                          FORMAT_STR_PRIORITY "(P" FORMAT_STR_PID ", T" FORMAT_STR_TID ") ",
 958                          entry_get_priority_string(entry),
 959                          entry->pid,
 960                          entry->tid);
 961         return 0;
 962 }
 963
 964 static int format_metadata_time(const dlogutil_entry_s *entry, char *prefix, char *suffix)
 965 {
 966         char *const buf_start = prefix;
 967         prefix = buf_add_time(prefix, METADATA_MAX_LEN, entry, true, true, true);
 968         if (!prefix)
 969                 return -1;
 970
 971         snprintf(prefix, METADATA_MAX_LEN - (prefix - buf_start),
 972                          " " FORMAT_STR_PRIORITY "/" FORMAT_STR_TAG "(" FORMAT_STR_PID "): ",
 973                          entry_get_priority_string(entry),
 974                          entry_get_tag_string(entry),
 975                          entry->pid);
 976         return 0;
 977 }
 978
 979 static int format_metadata_threadtime(const dlogutil_entry_s *entry, char *prefix, char *suffix)
 980 {
 981         char *const buf_start = prefix;
 982         prefix = buf_add_time(prefix, METADATA_MAX_LEN, entry, true, true, true);
 983         if (!prefix)
 984                 return -1;
 985
 986         snprintf(prefix, METADATA_MAX_LEN - (prefix - buf_start),
 987                          " " FORMAT_STR_PRIORITY "/" FORMAT_STR_TAG "(P" FORMAT_STR_PID ", T" FORMAT_STR_TID "): ",
 988                          entry_get_priority_string(entry),
 989                          entry_get_tag_string(entry),
 990                          entry->pid,
 991                          entry->tid);
 992         return 0;
 993 }
 994
 995 static int format_metadata_kerneltime(const dlogutil_entry_s *entry, char *prefix, char *suffix)
 996 {
 997         struct timespec t = entry_get_ts(entry, true, true);
 998         snprintf(prefix, METADATA_MAX_LEN,
 999                          FORMAT_STR_KERNELTIME " " FORMAT_STR_PRIORITY "/" FORMAT_STR_TAG "(P" FORMAT_STR_PID ", T" FORMAT_STR_TID "): ",
1000                          t.tv_sec,
1001                          NSEC_TO_MSEC(t.tv_nsec),
1002                          entry_get_priority_string(entry),
1003                          entry_get_tag_string(entry),
1004                          entry->pid,
1005                          entry->tid);
1006         return 0;
1007 }
1008
1009 static int format_metadata_recv_realtime(const dlogutil_entry_s *entry, char *prefix, char *suffix)
1010 {
1011         char *buf_start = prefix;
1012         prefix = buf_add_time(prefix, METADATA_MAX_LEN, entry, true, false, false);
1013         if (!prefix)
1014                 return -1;
1015
1016         snprintf(prefix, METADATA_MAX_LEN - (prefix - buf_start),
1017                          " " FORMAT_STR_PRIORITY "/" FORMAT_STR_TAG "(P" FORMAT_STR_PID ", T" FORMAT_STR_TID "): ",
1018                          entry_get_priority_string(entry),
1019                          entry_get_tag_string(entry),
1020                          entry->pid,
1021                          entry->tid);
1022         return 0;
1023 }
1024
1025 static int format_metadata_rwtime(const dlogutil_entry_s *entry, char *prefix, char *suffix)
1026 {
1027         struct timespec t = entry_get_ts(entry, true, true);
1028         char *const buf_start = prefix;
1029         prefix = buf_add_time(prefix, METADATA_MAX_LEN, entry, false, false, false);
1030         if (!prefix)
1031                 return -1;
1032
1033         snprintf(prefix, METADATA_MAX_LEN - (prefix - buf_start),
1034                          " [" FORMAT_STR_KERNELTIME "] " FORMAT_STR_PRIORITY "/" FORMAT_STR_TAG "(P" FORMAT_STR_PID ", T" FORMAT_STR_TID "): ",
1035                          t.tv_sec,
1036                          NSEC_TO_MSEC(t.tv_nsec),
1037                          entry_get_priority_string(entry),
1038                          entry_get_tag_string(entry),
1039                          entry->pid,
1040                          entry->tid);
1041         return 0;
1042 }
1043
1044 static int format_metadata_long(const dlogutil_entry_s *entry, char *prefix, char *suffix)
1045 {
1046         char time_str[sizeof "03-14 23:22:51.451"];
1047         buf_add_time(time_str, sizeof time_str, entry, true, false, true);
1048         if (!prefix)
1049                 return -1;
1050
1051         snprintf(prefix, METADATA_MAX_LEN,
1052                          "[ %s " FORMAT_STR_PRIORITY "/" FORMAT_STR_TAG " P" FORMAT_STR_PID ", T" FORMAT_STR_TID "]\n",
1053                          time_str,
1054                          entry_get_priority_string(entry),
1055                          entry_get_tag_string(entry),
1056                          entry->pid,
1057                          entry->tid);
1058         return 0;
1059 }
1060
1061 #define STATIC_BUFFER_SIZE 512
1062
1063 typedef struct {
1064         bool buf_created;
1065         char *buf_start;
1066         char *buf_position;
1067         const char *no_color_suffix;
1068         size_t allocated_space;
1069         size_t prefix_len;
1070         size_t suffix_len;
1071         size_t no_color_suffix_len;
1072         char prefix[COLORED_METADATA_MAX_LEN];
1073         char suffix[COLORED_METADATA_MAX_LEN];
1074 } print_buffer;
1075
1076 static int print_buffer_init(print_buffer *buffer, size_t message_len, size_t number_of_lines, struct log_write_buffer *wrbuf)
1077 {
1078         assert(buffer);
1079
1080         size_t needed_space = message_len + number_of_lines * (strlen(buffer->prefix) + strlen(buffer->suffix) + strlen(buffer->no_color_suffix)) + 1;
1081
1082         if (needed_space <= wrbuf->size - wrbuf->position) {
1083                 buffer->buf_start = wrbuf->data + wrbuf->position;
1084                 buffer->buf_created = false;
1085         } else {
1086                 buffer->buf_start = malloc(needed_space);
1087                 if (!buffer->buf_start)
1088                         return -1;
1089                 buffer->buf_created = true;
1090         }
1091
1092         buffer->allocated_space = needed_space;
1093         buffer->buf_position = buffer->buf_start;
1094         buffer->prefix_len = strlen(buffer->prefix);
1095         buffer->suffix_len = strlen(buffer->suffix);
1096         buffer->no_color_suffix_len = strlen(buffer->no_color_suffix);
1097         return 0;
1098 }
1099
1100 static void print_buffer_destroy(print_buffer *buffer)
1101 {
1102         if (buffer->buf_created)
1103                 free(buffer->buf_start);
1104         buffer->buf_created = false;
1105 }
1106
1107 static size_t print_buffer_remaining_space(print_buffer *buffer)
1108 {
1109         return buffer->allocated_space - (buffer->buf_position - buffer->buf_start);
1110 }
1111
1112 // string_limit has to be less or equal than the actual length of the string
1113 static int print_buffer_add_string(print_buffer *buffer, const char *string, size_t string_limit)
1114 {
1115         size_t len = print_buffer_remaining_space(buffer);
1116         if (string_limit < len)
1117                 len = string_limit;
1118
1119         memcpy(buffer->buf_position, string, len);
1120         buffer->buf_position += len;
1121         return len;
1122 }
1123
1124 static int print_buffer_add_string_line(print_buffer *buffer, const char *string, size_t string_limit, bool stop_on_eol)
1125 {
1126         if (!stop_on_eol)
1127                 return print_buffer_add_string(buffer, string, string_limit);
1128
1129         char *const buffer_end = buffer->buf_start + buffer->allocated_space;
1130         int i = 0;
1131         while (buffer->buf_position + i != buffer_end && i < string_limit && string[i] != 0 && string[i] != '\n') {
1132                 buffer->buf_position[i] = string[i];
1133                 ++i;
1134         }
1135         buffer->buf_position += i;
1136         return i;
1137 }
1138
1139 // returns how much of the line it used
1140 static size_t print_buffer_add_line(print_buffer *buffer, const char *line, size_t line_limit, bool stop_on_eol)
1141 {
1142         print_buffer_add_string(buffer, buffer->prefix, buffer->prefix_len);
1143
1144         size_t const offset = print_buffer_add_string_line(buffer, line, line_limit, stop_on_eol) + 1;
1145
1146         print_buffer_add_string(buffer, buffer->suffix, buffer->suffix_len);
1147         print_buffer_add_string(buffer, buffer->no_color_suffix, buffer->no_color_suffix_len);
1148
1149         return offset;
1150 }
1151
1152 static void add_colors(char *buf, uint8_t priority)
1153 {
1154         char temporary_buf[METADATA_MAX_LEN];
1155
1156         if (*buf == 0) // empty string has no colors
1157                 return;
1158
1159         strncpy(temporary_buf, buf, sizeof temporary_buf);
1160
1161         snprintf(buf, COLORED_METADATA_MAX_LEN, "%s%s%s",
1162                          get_pre_color(priority),
1163                          temporary_buf,
1164                          get_post_color(priority));
1165 }
1166
1167 static void print_buffer_add_colors(print_buffer *buffer, uint8_t priority)
1168 {
1169         add_colors(buffer->prefix, priority);
1170         add_colors(buffer->suffix, priority);
1171 }
1172
1173 static size_t scan_lines(const char *message, bool split_on_eol)
1174 {
1175
1176         assert(message);
1177
1178         if (!split_on_eol)
1179                 return 1;
1180
1181         size_t result = 1;
1182         while (*message != 0) {
1183                 if (*message == '\n')
1184                         ++result;
1185
1186                 ++message;
1187         }
1188
1189         return result;
1190 }
1191
1192 /**
1193  * @brief Print log line
1194  * @details Prints the given log entry to the supplied file descriptor
1195  * @param[in] p_format The format to use
1196  * @param[in] fd The file descriptor to write to
1197  * @param[in] entry The entry to print
1198  * @param[in,out] buf The write buffer to use
1199  * @returns On success, the number of bytes written; else a specific value
1200  * @retval -1 Memory allocation failure
1201  * @retval 0 Write failed
1202  */
1203 int log_print_log_line(
1204         struct log_format p_format,
1205         int fd,
1206         const dlogutil_entry_s *entry,
1207         struct log_write_buffer *wrbuf)
1208 {
1209         assert(entry);
1210         assert(wrbuf);
1211
1212         /* TODO: Return values are super iffy now.
1213          * The issue is that we sometimes don't write the log, but we still might want to return
1214          * a positive value. Right now we do some weird voodoo with the return values,
1215          * which means that the positive random are kinda random. */
1216
1217         if (wrbuf->data == NULL) {
1218                 const size_t size = 512;
1219                 wrbuf->data = alloca(size);
1220                 wrbuf->position = 0;
1221                 wrbuf->size = size;
1222
1223                 int r = log_print_log_line(p_format, fd, entry, wrbuf);
1224                 if (r == -1)
1225                         return -1;
1226
1227                 if (r > 0 && wrbuf->position != 0) {
1228                         r = write(fd, wrbuf->data, wrbuf->position);
1229                         if (r < 0)
1230                                 r = 0;
1231                 }
1232
1233                 wrbuf->data = NULL;
1234                 wrbuf->position = 0;
1235                 wrbuf->size = 0;
1236                 return r;
1237         }
1238
1239         if (p_format.format == FORMAT_JSON)
1240                 return log_print_line_format_json(fd, entry, wrbuf);
1241
1242         const struct format_info {
1243                 format_function format_metadata;
1244                 bool split_lines;
1245                 char *no_color_suffix;
1246         } format_info[] = {
1247                 [FORMAT_OFF]           = { NULL                         , false, ""    },
1248                 [FORMAT_BRIEF]         = { format_metadata_brief        , false, "\n"  },
1249                 [FORMAT_PROCESS]       = { format_metadata_process      , true , ""    },
1250                 [FORMAT_TAG]           = { format_metadata_tag          , false, "\n"  },
1251                 [FORMAT_THREAD]        = { format_metadata_thread       , false, "\n"  },
1252                 [FORMAT_RAW]           = { NULL                         , false, "\n"  },
1253                 [FORMAT_TIME]          = { format_metadata_time         , false, "\n"  },
1254                 [FORMAT_THREADTIME]    = { format_metadata_threadtime   , false, "\n"  },
1255                 [FORMAT_KERNELTIME]    = { format_metadata_kerneltime   , true , "\n"  },
1256                 [FORMAT_RECV_REALTIME] = { format_metadata_recv_realtime, true , "\n"  },
1257                 [FORMAT_RWTIME]        = { format_metadata_rwtime       , false, "\n"  },
1258                 [FORMAT_LONG]          = { format_metadata_long         , false, "\n\n"},
1259         };
1260
1261         if (p_format.format < 0 || p_format.format >= NELEMS(format_info))
1262                 return 0;
1263
1264         __attribute__ ((cleanup(print_buffer_destroy))) print_buffer buffer = {0};
1265
1266         const struct format_info *const format = &format_info[p_format.format];
1267         assert(format->no_color_suffix);
1268
1269         if (format->format_metadata
1270         &&  format->format_metadata(entry, buffer.prefix, buffer.suffix) != 0)
1271                 return -1;
1272
1273         if (p_format.color)
1274                 print_buffer_add_colors(&buffer, entry->priority);
1275
1276         buffer.no_color_suffix = format->no_color_suffix;
1277
1278         const char *message = entry_get_message_string(entry);
1279         size_t message_len = strlen(message);
1280         size_t number_of_lines = scan_lines(message, format->split_lines);
1281
1282         if (message_len > 0 && message[message_len-1] == '\n')
1283                 --message_len;
1284         const char *message_end = message + message_len;
1285
1286         if (print_buffer_init(&buffer, message_len, number_of_lines, wrbuf) != 0)
1287                 return -1;
1288
1289         while (message < message_end)
1290                 message += print_buffer_add_line(&buffer, message, message_end - message, format->split_lines);
1291
1292         return resolve_write(fd, wrbuf, buffer.buf_start, buffer.buf_position - buffer.buf_start);
1293 }
1294
1295 /**
1296  * @}
1297  */