src/tests/logprint.c

   1 // C
   2 #include <assert.h>
   3 #include <time.h>
   4
   5 // DLog
   6 #include <dlogutil-internal.h>
   7 #include <logprint.h>
   8 #include <ptrs_list.h>
   9
  10 static char buffer[10240];
  11 static size_t buffer_count = 0;
  12 static bool fake_write;
  13 static int partial_write;
  14 ssize_t __real_write(int fd, const void *buf, size_t count);
  15 ssize_t __wrap_write(int fd, const void *buf, size_t count)
  16 {
  17         if (partial_write)
  18                 return partial_write;
  19
  20         if (!fake_write)
  21                 return __real_write(fd, buf, count);
  22
  23         assert(count < sizeof buffer);
  24         memcpy(buffer, buf, count);
  25         buffer[count] = '\0';
  26         buffer_count = count;
  27
  28         return count;
  29 }
  30
  31 static bool fail_localtime_r;
  32 struct tm *__real_localtime_r(const time_t *timep, struct tm *result);
  33 struct tm *__wrap_localtime_r(const time_t *timep, struct tm *result)
  34 {
  35         return fail_localtime_r ? NULL : __real_localtime_r(timep, result);
  36 }
  37
  38 static int fail_alloc;
  39 void *__real_malloc(size_t size);
  40 void *__real_calloc(size_t nmemb, size_t size);
  41 void *__wrap_malloc(size_t size)
  42 {
  43         if (fail_alloc) {
  44                 assert(size > 512);
  45                 return NULL;
  46         }
  47
  48         return __real_malloc(size);
  49 }
  50 void *__wrap_calloc(size_t nmemb, size_t size)
  51 {
  52         return fail_alloc ? NULL : __real_calloc(nmemb, size);
  53 }
  54
  55 static bool fail_strndup;
  56 char *__real_strndup(const char *s, size_t n);
  57 char *__wrap_strndup(const char *s, size_t n)
  58 {
  59         return fail_strndup ? NULL : __real_strndup(s, n);
  60 }
  61
  62 static bool fail_strdup;
  63 char *__real_strdup(const char *s);
  64 char *__wrap_strdup(const char *s)
  65 {
  66         return fail_strdup ? NULL : __real_strdup(s);
  67 }
  68
  69 static bool fail_list_add;
  70 bool __real_list_add(list_head *head, elem_value value);
  71 bool __wrap_list_add(list_head *head, elem_value value)
  72 {
  73         return fail_list_add ? false : __real_list_add(head, value);
  74 }
  75
  76 /* Timestamps are shown in the everyday format so
  77  * it's good to be able to work with those numbers
  78  * where possible instead of the underlying single
  79  * integer (but see below). */
  80
  81 #define SECONDS 1 // the base unit of the sec timestamp
  82 #define MINUTES (60 * SECONDS)
  83 #define HOURS   (60 * MINUTES)
  84 #define DAYS    (24 * HOURS)
  85
  86 #define JANUARY  (-1 * DAYS) // dates start from Jan 01, not Jan 00
  87 #define FEBRUARY (JANUARY  + 31 * DAYS)
  88 #define MARCH    (FEBRUARY + 28 * DAYS) // 1970, so no 29th
  89
  90 /* The nano timestamp is a bit more of a monolith,
  91  * but can still be meaningfully split up into the
  92  * milliseconds part and the remainder since all
  93  * timestamps seem to only show the former. */
  94
  95 #define  NANOSECONDS 1
  96 #define MICROSECONDS (1000 * NANOSECONDS)
  97 #define MILLISECONDS (1000 * MICROSECONDS)
  98
  99 static void standard_test_msg(struct dlogutil_entry_with_msg *entry, const char *msg, size_t msg_len)
 100 {
 101         *entry = (struct dlogutil_entry_with_msg) {
 102                 .header = {
 103                         .len            = sizeof entry->header + msg_len,
 104                         .priority       = DLOG_INFO,
 105                         .pid            = 4228,
 106                         .tid            = 4567,
 107                         .sec_sent_mono  = 3205048,
 108                         .sec_sent_real  =    MARCH + 14*DAYS + 23*HOURS + 22*MINUTES + 51*SECONDS,
 109                         .sec_recv_mono  = 365467,
 110                         .sec_recv_real  = FEBRUARY +  1*DAYS +  0*HOURS +  5*MINUTES + 17*SECONDS,
 111                         .nsec_sent_mono = 235*MILLISECONDS + 123*MICROSECONDS + 213*NANOSECONDS,
 112                         .nsec_sent_real = 451*MILLISECONDS + 435*MICROSECONDS + 135*NANOSECONDS,
 113                         .nsec_recv_mono = 346*MILLISECONDS + 253*MICROSECONDS + 662*NANOSECONDS,
 114                         .nsec_recv_real = 734*MILLISECONDS + 543*MICROSECONDS + 254*NANOSECONDS,
 115                         .tag_len        = -1,
 116                 },
 117         };
 118
 119         memcpy(entry->msg, msg, msg_len); // strcpy won't do because msg has an embedded \0 as the tag delimiter
 120         for (size_t i = 0; i < msg_len; ++i)
 121                 if (!msg[i]) {
 122                         entry->header.tag_len = i;
 123                         break;
 124                 }
 125         assert(entry->header.tag_len >= 0);
 126
 127         /* Despite the comment about the single int above,
 128          * sometimes we still have to work with it. Make
 129          * sure we know the other representation in each
 130          * case so that we can easily identify failures. */
 131         assert(entry->header.sec_sent_mono == FEBRUARY +  7*DAYS +  2*HOURS + 17*MINUTES + 28*SECONDS);
 132         assert(entry->header.sec_sent_real == 6304971);
 133         assert(entry->header.sec_recv_mono ==  JANUARY +  5*DAYS +  5*HOURS + 31*MINUTES +  7*SECONDS);
 134         assert(entry->header.sec_recv_real == 2678717);
 135 }
 136
 137 static void invalid_test_msg(struct dlogutil_entry_with_msg *entry, const char *msg, size_t msg_len)
 138 {
 139         standard_test_msg(entry, msg, msg_len);
 140
 141         entry->header.pid = -123;
 142         entry->header.tid = -456;
 143         entry->header.nsec_sent_mono = -78;
 144         entry->header.nsec_sent_real = -90;
 145
 146         fixup_pipe_msg(entry, msg_len);
 147 }
 148
 149 struct logprint_test_case {
 150         log_print_format format;
 151         log_priority priority;
 152         bool color_enabled;
 153         const char *result;
 154 };
 155
 156 void check_logprint_testcases(struct dlogutil_entry_with_msg *entry, const struct logprint_test_case *tests, size_t tests_n)
 157 {
 158         fake_write = true;
 159
 160         for (size_t i = 0; i < tests_n; ++i) {
 161                 entry->header.priority = tests[i].priority;
 162                 assert(log_print_log_line((struct log_format){
 163                         .format = tests[i].format,
 164                         .color = tests[i].color_enabled,
 165                 }, 0, &entry->header, &(struct log_write_buffer) { }) == 1);
 166                 fprintf(stderr, "format=%d, expected %s<, got %s<", tests[i].format, tests[i].result, buffer);
 167                 assert(!strcmp(tests[i].result, buffer));
 168         }
 169
 170         fake_write = false;
 171 }
 172
 173 void check_logprint_testcases_standard(const char *msg, size_t msg_len, const struct logprint_test_case *tests, size_t tests_n)
 174 {
 175         struct dlogutil_entry_with_msg entry;
 176         standard_test_msg(&entry, msg, msg_len);
 177
 178         check_logprint_testcases(&entry, tests, tests_n);
 179 }
 180
 181 void check_logprint_testcases_invalid(const char *msg, size_t msg_len, const struct logprint_test_case *tests, size_t tests_n)
 182 {
 183         struct dlogutil_entry_with_msg entry;
 184         invalid_test_msg(&entry, msg, msg_len);
 185
 186         check_logprint_testcases(&entry, tests, tests_n);
 187 }
 188
 189 #define CHECK_LOGPRINT_TESTCASES(MSG, TESTS) check_logprint_testcases_standard(MSG, sizeof MSG, TESTS, NELEMS(TESTS))
 190 #define CHECK_LOGPRINT_TESTCASES_INVALID(MSG, TESTS) check_logprint_testcases_invalid(MSG, sizeof MSG, TESTS, NELEMS(TESTS))
 191
 192 void check_log_print_log_line(void)
 193 {
 194         static const struct logprint_test_case tests_basic[] = {
 195                 // formats using the SENT timestamp
 196                 {FORMAT_TIME         , DLOG_INFO, false, "03-14 23:22:51.451+0000 I/BASIC TAG( 4228): Basic message.\n"             },
 197                 {FORMAT_LONG         , DLOG_INFO, false, "[ 03-14 23:22:51.451 I/BASIC TAG P 4228, T 4567]\nBasic message.\n\n"     },
 198                 {FORMAT_THREADTIME   , DLOG_INFO, false, "03-14 23:22:51.451+0000 I/BASIC TAG (P 4228, T 4567): Basic message.\n"   },
 199                 {FORMAT_KERNELTIME   , DLOG_INFO, false, "3205048.235 I/BASIC TAG(P 4228, T 4567): Basic message.\n"                },
 200
 201                 // formats using the RECV timestamp
 202                 {FORMAT_RECV_REALTIME, DLOG_INFO, false, "02-01 00:05:17.734 I/BASIC TAG(P 4228, T 4567): Basic message.\n"         },
 203                 {FORMAT_RWTIME       , DLOG_INFO, false, "02-01 00:05:17 [3205048.235] I/BASIC TAG(P 4228, T 4567): Basic message.\n"},
 204
 205                 // formats without a timestamp
 206                 {FORMAT_BRIEF        , DLOG_INFO, false, "I/BASIC TAG( 4228): Basic message.\n"                                     },
 207                 {FORMAT_PROCESS      , DLOG_INFO, false, "I( 4228) Basic message.  (BASIC TAG)\n"                                   },
 208                 {FORMAT_TAG          , DLOG_INFO, false, "I/BASIC TAG: Basic message.\n"                                            },
 209                 {FORMAT_THREAD       , DLOG_INFO, false, "I(P 4228, T 4567) Basic message.\n"                                       },
 210                 {FORMAT_RAW          , DLOG_INFO, false, "Basic message.\n"                                                         },
 211                 // JSON
 212                 {FORMAT_JSON         , DLOG_INFO, false, "{"
 213                         "\"priority\":\"info\","
 214                         "\"pid\":4228,"
 215                         "\"tid\":4567,"
 216                         "\"recv_real\":\"1970-02-01T00:05:17+0000\","
 217                         "\"recv_mono\":365467.346253662,"
 218                         "\"sent_real\":\"1970-03-14T23:22:51+0000\","
 219                         "\"sent_mono\":3205048.235123213,"
 220                         "\"tag\":\"BASIC TAG\","
 221                         "\"msg\":\"Basic message.\""
 222                 "}\n"},
 223         };
 224         CHECK_LOGPRINT_TESTCASES("BASIC TAG\0Basic message.", tests_basic);
 225
 226         // Short tag
 227         static const struct logprint_test_case tests_short_tag[] = {
 228                 {FORMAT_TIME         , DLOG_INFO, false, "03-14 23:22:51.451+0000 I/SHORT   ( 4228): Basic message.\n"             },
 229                 {FORMAT_LONG         , DLOG_INFO, false, "[ 03-14 23:22:51.451 I/SHORT    P 4228, T 4567]\nBasic message.\n\n"     },
 230                 {FORMAT_THREADTIME   , DLOG_INFO, false, "03-14 23:22:51.451+0000 I/SHORT    (P 4228, T 4567): Basic message.\n"   },
 231                 {FORMAT_KERNELTIME   , DLOG_INFO, false, "3205048.235 I/SHORT   (P 4228, T 4567): Basic message.\n"                },
 232                 {FORMAT_RECV_REALTIME, DLOG_INFO, false, "02-01 00:05:17.734 I/SHORT   (P 4228, T 4567): Basic message.\n"         },
 233                 {FORMAT_RWTIME       , DLOG_INFO, false, "02-01 00:05:17 [3205048.235] I/SHORT   (P 4228, T 4567): Basic message.\n"},
 234                 {FORMAT_BRIEF        , DLOG_INFO, false, "I/SHORT   ( 4228): Basic message.\n"                                     },
 235                 {FORMAT_PROCESS      , DLOG_INFO, false, "I( 4228) Basic message.  (SHORT)\n"                                      },
 236                 {FORMAT_TAG          , DLOG_INFO, false, "I/SHORT   : Basic message.\n"                                            },
 237         };
 238         CHECK_LOGPRINT_TESTCASES("SHORT\0Basic message.", tests_short_tag);
 239
 240         // Color coded headers
 241         static const struct logprint_test_case tests_colors[] = {
 242                 // Fatal
 243                 {FORMAT_TIME         , DLOG_FATAL, true, "\033[35;1m03-14 23:22:51.451+0000 F/COLORFUL TAG( 4228): \033[0mBasic message.\n"             },
 244                 {FORMAT_LONG         , DLOG_FATAL, true, "\033[35;1m[ 03-14 23:22:51.451 F/COLORFUL TAG P 4228, T 4567]\n\033[0mBasic message.\n\n"     },
 245                 {FORMAT_THREADTIME   , DLOG_FATAL, true, "\033[35;1m03-14 23:22:51.451+0000 F/COLORFUL TAG (P 4228, T 4567): \033[0mBasic message.\n"   },
 246                 {FORMAT_KERNELTIME   , DLOG_FATAL, true, "\033[35;1m3205048.235 F/COLORFUL TAG(P 4228, T 4567): \033[0mBasic message.\n"                },
 247                 {FORMAT_RECV_REALTIME, DLOG_FATAL, true, "\033[35;1m02-01 00:05:17.734 F/COLORFUL TAG(P 4228, T 4567): \033[0mBasic message.\n"         },
 248                 {FORMAT_RWTIME       , DLOG_FATAL, true, "\033[35;1m02-01 00:05:17 [3205048.235] F/COLORFUL TAG(P 4228, T 4567): \033[0mBasic message.\n"},
 249                 {FORMAT_BRIEF        , DLOG_FATAL, true, "\033[35;1mF/COLORFUL TAG( 4228): \033[0mBasic message.\n"                                     },
 250                 {FORMAT_PROCESS      , DLOG_FATAL, true, "\033[35;1mF( 4228) \033[0mBasic message.\033[35;1m  (COLORFUL TAG)\n\033[0m"                  },
 251                 {FORMAT_TAG          , DLOG_FATAL, true, "\033[35;1mF/COLORFUL TAG: \033[0mBasic message.\n"                                            },
 252                 {FORMAT_THREAD       , DLOG_FATAL, true, "\033[35;1mF(P 4228, T 4567) \033[0mBasic message.\n"                                          },
 253                 {FORMAT_RAW          , DLOG_FATAL, true, "Basic message.\n"                                                                             },
 254
 255                 // Error
 256                 {FORMAT_TIME         , DLOG_ERROR, true, "\033[31;1m03-14 23:22:51.451+0000 E/COLORFUL TAG( 4228): \033[0mBasic message.\n"             },
 257                 {FORMAT_LONG         , DLOG_ERROR, true, "\033[31;1m[ 03-14 23:22:51.451 E/COLORFUL TAG P 4228, T 4567]\n\033[0mBasic message.\n\n"     },
 258                 {FORMAT_THREADTIME   , DLOG_ERROR, true, "\033[31;1m03-14 23:22:51.451+0000 E/COLORFUL TAG (P 4228, T 4567): \033[0mBasic message.\n"   },
 259                 {FORMAT_KERNELTIME   , DLOG_ERROR, true, "\033[31;1m3205048.235 E/COLORFUL TAG(P 4228, T 4567): \033[0mBasic message.\n"                },
 260                 {FORMAT_RECV_REALTIME, DLOG_ERROR, true, "\033[31;1m02-01 00:05:17.734 E/COLORFUL TAG(P 4228, T 4567): \033[0mBasic message.\n"         },
 261                 {FORMAT_RWTIME       , DLOG_ERROR, true, "\033[31;1m02-01 00:05:17 [3205048.235] E/COLORFUL TAG(P 4228, T 4567): \033[0mBasic message.\n"},
 262                 {FORMAT_BRIEF        , DLOG_ERROR, true, "\033[31;1mE/COLORFUL TAG( 4228): \033[0mBasic message.\n"                                     },
 263                 {FORMAT_PROCESS      , DLOG_ERROR, true, "\033[31;1mE( 4228) \033[0mBasic message.\033[31;1m  (COLORFUL TAG)\n\033[0m"                  },
 264                 {FORMAT_TAG          , DLOG_ERROR, true, "\033[31;1mE/COLORFUL TAG: \033[0mBasic message.\n"                                            },
 265                 {FORMAT_THREAD       , DLOG_ERROR, true, "\033[31;1mE(P 4228, T 4567) \033[0mBasic message.\n"                                          },
 266                 {FORMAT_RAW          , DLOG_ERROR, true, "Basic message.\n"                                                                             },
 267
 268                 // Warning
 269                 {FORMAT_TIME         , DLOG_WARN , true, "\033[33;1m03-14 23:22:51.451+0000 W/COLORFUL TAG( 4228): \033[0mBasic message.\n"             },
 270                 {FORMAT_LONG         , DLOG_WARN , true, "\033[33;1m[ 03-14 23:22:51.451 W/COLORFUL TAG P 4228, T 4567]\n\033[0mBasic message.\n\n"     },
 271                 {FORMAT_THREADTIME   , DLOG_WARN , true, "\033[33;1m03-14 23:22:51.451+0000 W/COLORFUL TAG (P 4228, T 4567): \033[0mBasic message.\n"   },
 272                 {FORMAT_KERNELTIME   , DLOG_WARN , true, "\033[33;1m3205048.235 W/COLORFUL TAG(P 4228, T 4567): \033[0mBasic message.\n"                },
 273                 {FORMAT_RECV_REALTIME, DLOG_WARN , true, "\033[33;1m02-01 00:05:17.734 W/COLORFUL TAG(P 4228, T 4567): \033[0mBasic message.\n"         },
 274                 {FORMAT_RWTIME       , DLOG_WARN , true, "\033[33;1m02-01 00:05:17 [3205048.235] W/COLORFUL TAG(P 4228, T 4567): \033[0mBasic message.\n"},
 275                 {FORMAT_BRIEF        , DLOG_WARN , true, "\033[33;1mW/COLORFUL TAG( 4228): \033[0mBasic message.\n"                                     },
 276                 {FORMAT_PROCESS      , DLOG_WARN , true, "\033[33;1mW( 4228) \033[0mBasic message.\033[33;1m  (COLORFUL TAG)\n\033[0m"                  },
 277                 {FORMAT_TAG          , DLOG_WARN , true, "\033[33;1mW/COLORFUL TAG: \033[0mBasic message.\n"                                            },
 278                 {FORMAT_THREAD       , DLOG_WARN , true, "\033[33;1mW(P 4228, T 4567) \033[0mBasic message.\n"                                          },
 279                 {FORMAT_RAW          , DLOG_WARN , true, "Basic message.\n"                                                                             },
 280
 281                 // Information -- no color coding needed
 282                 {FORMAT_TIME         , DLOG_INFO , true , "03-14 23:22:51.451+0000 I/COLORFUL TAG( 4228): Basic message.\n"             },
 283                 {FORMAT_LONG         , DLOG_INFO , true , "[ 03-14 23:22:51.451 I/COLORFUL TAG P 4228, T 4567]\nBasic message.\n\n"     },
 284                 {FORMAT_THREADTIME   , DLOG_INFO , true , "03-14 23:22:51.451+0000 I/COLORFUL TAG (P 4228, T 4567): Basic message.\n"   },
 285                 {FORMAT_KERNELTIME   , DLOG_INFO , true , "3205048.235 I/COLORFUL TAG(P 4228, T 4567): Basic message.\n"                },
 286                 {FORMAT_RECV_REALTIME, DLOG_INFO , true , "02-01 00:05:17.734 I/COLORFUL TAG(P 4228, T 4567): Basic message.\n"         },
 287                 {FORMAT_RWTIME       , DLOG_INFO , true , "02-01 00:05:17 [3205048.235] I/COLORFUL TAG(P 4228, T 4567): Basic message.\n"},
 288                 {FORMAT_BRIEF        , DLOG_INFO , true , "I/COLORFUL TAG( 4228): Basic message.\n"                                     },
 289                 {FORMAT_PROCESS      , DLOG_INFO , true , "I( 4228) Basic message.  (COLORFUL TAG)\n"                                   },
 290                 {FORMAT_TAG          , DLOG_INFO , true , "I/COLORFUL TAG: Basic message.\n"                                            },
 291                 {FORMAT_THREAD       , DLOG_INFO , true , "I(P 4228, T 4567) Basic message.\n"                                          },
 292                 {FORMAT_RAW          , DLOG_INFO , true , "Basic message.\n"                                                            },
 293
 294                 // Color coding disabled
 295                 {FORMAT_TIME         , DLOG_FATAL, false, "03-14 23:22:51.451+0000 F/COLORFUL TAG( 4228): Basic message.\n"             },
 296         };
 297         CHECK_LOGPRINT_TESTCASES("COLORFUL TAG\0Basic message.", tests_colors);
 298
 299         // Empty tag has special handling and gets replaced.
 300         static const struct logprint_test_case tests_tagless[] = {
 301                 // formats using the SENT timestamp
 302                 {FORMAT_RECV_REALTIME, DLOG_INFO, false, "02-01 00:05:17.734 I/DLOG_ERROR_NOTAG(P 4228, T 4567): Tagless\n"},
 303                 {FORMAT_BRIEF        , DLOG_INFO, false, "I/DLOG_ERROR_NOTAG( 4228): Tagless\n"                            },
 304                 {FORMAT_PROCESS      , DLOG_INFO, false, "I( 4228) Tagless  (DLOG_ERROR_NOTAG)\n"                          },
 305                 {FORMAT_JSON         , DLOG_INFO, false, "{"
 306                         "\"priority\":\"info\","
 307                         "\"pid\":4228,"
 308                         "\"tid\":4567,"
 309                         "\"recv_real\":\"1970-02-01T00:05:17+0000\","
 310                         "\"recv_mono\":365467.346253662,"
 311                         "\"sent_real\":\"1970-03-14T23:22:51+0000\","
 312                         "\"sent_mono\":3205048.235123213,"
 313                         "\"tag\":\"DLOG_ERROR_NOTAG\","
 314                         "\"msg\":\"Tagless\""
 315                 "}\n"},
 316         };
 317         CHECK_LOGPRINT_TESTCASES("\0Tagless", tests_tagless);
 318
 319         /* Some formats insert the extra info (timestamp, tag etc) every time they
 320          * find a line break. The tag itself is never broken up though. */
 321         static const struct logprint_test_case tests_linebreak[] = {
 322                 {FORMAT_TIME, DLOG_INFO, false,
 323                         "03-14 23:22:51.451+0000 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES( 4228): And\n"
 324                         "03-14 23:22:51.451+0000 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES( 4228): so\n"
 325                         "03-14 23:22:51.451+0000 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES( 4228): does\n"
 326                         "03-14 23:22:51.451+0000 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES( 4228): this\n"
 327                         "03-14 23:22:51.451+0000 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES( 4228): message.\n" },
 328                 {FORMAT_LONG, DLOG_INFO, false,
 329                         "[ 03-14 23:22:51.451 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES P 4228, T 4567]\n"
 330                         "And\nso\ndoes\nthis\nmessage.\n\n" },
 331                 {FORMAT_THREADTIME, DLOG_INFO, true ,
 332                         "03-14 23:22:51.451+0000 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES (P 4228, T 4567): And\n"
 333                         "03-14 23:22:51.451+0000 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES (P 4228, T 4567): so\n"
 334                         "03-14 23:22:51.451+0000 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES (P 4228, T 4567): does\n"
 335                         "03-14 23:22:51.451+0000 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES (P 4228, T 4567): this\n"
 336                         "03-14 23:22:51.451+0000 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES (P 4228, T 4567): message.\n" },
 337                 {FORMAT_KERNELTIME, DLOG_INFO, false,
 338                         "3205048.235 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES(P 4228, T 4567): And\n"
 339                         "3205048.235 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES(P 4228, T 4567): so\n"
 340                         "3205048.235 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES(P 4228, T 4567): does\n"
 341                         "3205048.235 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES(P 4228, T 4567): this\n"
 342                         "3205048.235 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES(P 4228, T 4567): message.\n" },
 343                 {FORMAT_RECV_REALTIME, DLOG_INFO, false,
 344                         "02-01 00:05:17.734 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES(P 4228, T 4567): And\n"
 345                         "02-01 00:05:17.734 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES(P 4228, T 4567): so\n"
 346                         "02-01 00:05:17.734 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES(P 4228, T 4567): does\n"
 347                         "02-01 00:05:17.734 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES(P 4228, T 4567): this\n"
 348                         "02-01 00:05:17.734 I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES(P 4228, T 4567): message.\n" },
 349                 {FORMAT_RWTIME, DLOG_INFO, false,
 350                         "02-01 00:05:17 [3205048.235] I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES(P 4228, T 4567): And\n"
 351                         "02-01 00:05:17 [3205048.235] I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES(P 4228, T 4567): so\n"
 352                         "02-01 00:05:17 [3205048.235] I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES(P 4228, T 4567): does\n"
 353                         "02-01 00:05:17 [3205048.235] I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES(P 4228, T 4567): this\n"
 354                         "02-01 00:05:17 [3205048.235] I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES(P 4228, T 4567): message.\n" },
 355                 {FORMAT_BRIEF, DLOG_INFO, false,
 356                         "I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES( 4228): And\n"
 357                         "I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES( 4228): so\n"
 358                         "I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES( 4228): does\n"
 359                         "I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES( 4228): this\n"
 360                         "I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES( 4228): message.\n" },
 361                 {FORMAT_PROCESS, DLOG_INFO, false,
 362                         "I( 4228) And  (THIS\nTAG\nTAKES\nMULTIPLE\nLINES)\n"
 363                         "I( 4228) so  (THIS\nTAG\nTAKES\nMULTIPLE\nLINES)\n"
 364                         "I( 4228) does  (THIS\nTAG\nTAKES\nMULTIPLE\nLINES)\n"
 365                         "I( 4228) this  (THIS\nTAG\nTAKES\nMULTIPLE\nLINES)\n"
 366                         "I( 4228) message.  (THIS\nTAG\nTAKES\nMULTIPLE\nLINES)\n" },
 367                 {FORMAT_TAG, DLOG_INFO, false,
 368                         "I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES: And\n"
 369                         "I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES: so\n"
 370                         "I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES: does\n"
 371                         "I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES: this\n"
 372                         "I/THIS\nTAG\nTAKES\nMULTIPLE\nLINES: message.\n" },
 373                 {FORMAT_THREAD, DLOG_INFO, false,
 374                         "I(P 4228, T 4567) And\n"
 375                         "I(P 4228, T 4567) so\n"
 376                         "I(P 4228, T 4567) does\n"
 377                         "I(P 4228, T 4567) this\n"
 378                         "I(P 4228, T 4567) message.\n" },
 379                 {FORMAT_RAW, DLOG_INFO, false,
 380                         "And\nso\ndoes\nthis\nmessage.\n" },
 381         };
 382         CHECK_LOGPRINT_TESTCASES("THIS\nTAG\nTAKES\nMULTIPLE\nLINES\0And\nso\ndoes\nthis\nmessage.", tests_linebreak);
 383
 384         /* The extras' length gets to be capped (regardless
 385          * of which side of the message they are put on). */
 386         static const struct logprint_test_case tests_long_metadata[] = {
 387                 // Uncolored
 388                 {FORMAT_LONG, DLOG_INFO, false,
 389                         "[ 03-14 23:22:51.451 I/THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS"
 390                         "foo1\nfoo2\n\n" },
 391                 {FORMAT_KERNELTIME, DLOG_INFO, false,
 392                         "3205048.235 I/THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTfoo1\n"
 393                         "3205048.235 I/THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTfoo2\n" },
 394                 {FORMAT_RECV_REALTIME, DLOG_INFO, false,
 395                         "02-01 00:05:17.734 I/THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS Ifoo1\n"
 396                         "02-01 00:05:17.734 I/THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS Ifoo2\n" },
 397                 {FORMAT_PROCESS, DLOG_INFO, false,
 398                         "I( 4228) foo1  (THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TA"
 399                         "I( 4228) foo2  (THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TA" },
 400
 401                 // Colored
 402                 {FORMAT_LONG, DLOG_WARN, true,
 403                         "\033[33;1m[ 03-14 23:22:51.451 W/THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS\033[0m"
 404                         "foo1\nfoo2\n\n" },
 405                 {FORMAT_KERNELTIME, DLOG_WARN, true,
 406                         "\033[33;1m3205048.235 W/THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGT\033[0mfoo1\n"
 407                         "\033[33;1m3205048.235 W/THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGT\033[0mfoo2\n" },
 408                 {FORMAT_RECV_REALTIME, DLOG_WARN, true,
 409                         "\033[33;1m02-01 00:05:17.734 W/THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS I\033[0mfoo1\n"
 410                         "\033[33;1m02-01 00:05:17.734 W/THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS I\033[0mfoo2\n" },
 411                 {FORMAT_PROCESS, DLOG_WARN, true,
 412                         "\033[33;1mW( 4228) \033[0mfoo1\033[33;1m  (THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TA\033[0m"
 413                         "\033[33;1mW( 4228) \033[0mfoo2\033[33;1m  (THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TA\033[0m" },
 414         };
 415         CHECK_LOGPRINT_TESTCASES("THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH ~ THIS TAG IS OVER 128 CHARS IN LENGTH\0foo1\nfoo2", tests_long_metadata);
 416
 417         static const struct logprint_test_case tests_no_msg[] = {
 418                 {FORMAT_BRIEF  , DLOG_INFO, false, "I/SOME_TAG( 4228): DLOG_ERROR_NOMSG\n"                                    },
 419                 {FORMAT_RAW    , DLOG_INFO, false, "DLOG_ERROR_NOMSG\n"                                                       },
 420                 {FORMAT_PROCESS, DLOG_INFO, false, "I( 4228) DLOG_ERROR_NOMSG  (SOME_TAG)\n"                                  },
 421                 {FORMAT_LONG   , DLOG_INFO, false, "[ 03-14 23:22:51.451 I/SOME_TAG P 4228, T 4567]\n"
 422                                                    "DLOG_ERROR_NOMSG\n\n"                                                     },
 423                 {FORMAT_JSON   , DLOG_INFO, false, "{"
 424                         "\"priority\":\"info\","
 425                         "\"pid\":4228,"
 426                         "\"tid\":4567,"
 427                         "\"recv_real\":\"1970-02-01T00:05:17+0000\","
 428                         "\"recv_mono\":365467.346253662,"
 429                         "\"sent_real\":\"1970-03-14T23:22:51+0000\","
 430                         "\"sent_mono\":3205048.235123213,"
 431                         "\"tag\":\"SOME_TAG\","
 432                         "\"msg\":\"DLOG_ERROR_NOMSG\""
 433                 "}\n"},
 434
 435                 {FORMAT_BRIEF  , DLOG_WARN,  true, "\033[33;1mW/SOME_TAG( 4228): \033[0mDLOG_ERROR_NOMSG\n"                   },
 436                 {FORMAT_RAW    , DLOG_WARN,  true, "DLOG_ERROR_NOMSG\n"                                                       },
 437                 {FORMAT_PROCESS, DLOG_WARN,  true, "\033[33;1mW( 4228) \033[0mDLOG_ERROR_NOMSG\033[33;1m  (SOME_TAG)\n\033[0m"},
 438                 {FORMAT_LONG   , DLOG_WARN,  true, "\033[33;1m[ 03-14 23:22:51.451 W/SOME_TAG P 4228, T 4567]\n\033[0m"
 439                                                    "DLOG_ERROR_NOMSG\n\n"                                                     },
 440         };
 441         CHECK_LOGPRINT_TESTCASES("SOME_TAG\0", tests_no_msg);
 442
 443         static const struct logprint_test_case tests_no_nothing[] = {
 444                 {FORMAT_BRIEF  , DLOG_INFO, false, "I/DLOG_ERROR_NOTAG( 4228): DLOG_ERROR_NOMSG\n"                            },
 445                 {FORMAT_RAW    , DLOG_INFO, false, "DLOG_ERROR_NOMSG\n"                                                       },
 446                 {FORMAT_PROCESS, DLOG_INFO, false, "I( 4228) DLOG_ERROR_NOMSG  (DLOG_ERROR_NOTAG)\n"                          },
 447                 {FORMAT_LONG   , DLOG_INFO, false, "[ 03-14 23:22:51.451 I/DLOG_ERROR_NOTAG P 4228, T 4567]\n"
 448                                                    "DLOG_ERROR_NOMSG\n\n"                                                     },
 449
 450                 {FORMAT_BRIEF  , DLOG_WARN,  true, "\033[33;1mW/DLOG_ERROR_NOTAG( 4228): \033[0mDLOG_ERROR_NOMSG\n"           },
 451                 {FORMAT_RAW    , DLOG_WARN,  true, "DLOG_ERROR_NOMSG\n"                                                       },
 452                 {FORMAT_PROCESS, DLOG_WARN,  true, "\033[33;1mW( 4228) \033[0mDLOG_ERROR_NOMSG\033[33;1m  "
 453                                                    "(DLOG_ERROR_NOTAG)\n\033[0m"},
 454                 {FORMAT_LONG   , DLOG_WARN,  true, "\033[33;1m[ 03-14 23:22:51.451 W/DLOG_ERROR_NOTAG P 4228, T 4567]\n\033[0m"
 455                                                    "DLOG_ERROR_NOMSG\n\n"                                                     },
 456         };
 457         CHECK_LOGPRINT_TESTCASES("\0", tests_no_nothing);
 458
 459         static const struct logprint_test_case tests_two_zeros[] = {
 460                 {FORMAT_BRIEF  , DLOG_INFO, false, "I/DLOG_ERROR_NOTAG( 4228): DLOG_ERROR_NOMSG\n"                            },
 461                 {FORMAT_RAW    , DLOG_INFO, false, "DLOG_ERROR_NOMSG\n"                                                       },
 462                 {FORMAT_PROCESS, DLOG_INFO, false, "I( 4228) DLOG_ERROR_NOMSG  (DLOG_ERROR_NOTAG)\n"                          },
 463                 {FORMAT_LONG   , DLOG_INFO, false, "[ 03-14 23:22:51.451 I/DLOG_ERROR_NOTAG P 4228, T 4567]\n"
 464                                                    "DLOG_ERROR_NOMSG\n\n"                                                     },
 465
 466                 {FORMAT_BRIEF  , DLOG_WARN,  true, "\033[33;1mW/DLOG_ERROR_NOTAG( 4228): \033[0mDLOG_ERROR_NOMSG\n"           },
 467                 {FORMAT_RAW    , DLOG_WARN,  true, "DLOG_ERROR_NOMSG\n"                                                       },
 468                 {FORMAT_PROCESS, DLOG_WARN,  true, "\033[33;1mW( 4228) \033[0mDLOG_ERROR_NOMSG\033[33;1m  "
 469                                                    "(DLOG_ERROR_NOTAG)\n\033[0m"},
 470                 {FORMAT_LONG   , DLOG_WARN,  true, "\033[33;1m[ 03-14 23:22:51.451 W/DLOG_ERROR_NOTAG P 4228, T 4567]\n\033[0m"
 471                                                    "DLOG_ERROR_NOMSG\n\n"                                                     },
 472         };
 473         CHECK_LOGPRINT_TESTCASES("\0\0", tests_two_zeros);
 474
 475         static const struct logprint_test_case tests_garbage[] = {
 476                 {FORMAT_BRIEF  , DLOG_INFO, false, "I/DLOG_ERROR_NOTAG( 4228): DLOG_ERROR_NOMSG\n"                            },
 477                 {FORMAT_RAW    , DLOG_INFO, false, "DLOG_ERROR_NOMSG\n"                                                       },
 478                 {FORMAT_PROCESS, DLOG_INFO, false, "I( 4228) DLOG_ERROR_NOMSG  (DLOG_ERROR_NOTAG)\n"                          },
 479                 {FORMAT_LONG   , DLOG_INFO, false, "[ 03-14 23:22:51.451 I/DLOG_ERROR_NOTAG P 4228, T 4567]\n"
 480                                                    "DLOG_ERROR_NOMSG\n\n"                                                     },
 481
 482                 {FORMAT_BRIEF  , DLOG_WARN,  true, "\033[33;1mW/DLOG_ERROR_NOTAG( 4228): \033[0mDLOG_ERROR_NOMSG\n"           },
 483                 {FORMAT_RAW    , DLOG_WARN,  true, "DLOG_ERROR_NOMSG\n"                                                       },
 484                 {FORMAT_PROCESS, DLOG_WARN,  true, "\033[33;1mW( 4228) \033[0mDLOG_ERROR_NOMSG\033[33;1m  "
 485                                                    "(DLOG_ERROR_NOTAG)\n\033[0m"},
 486                 {FORMAT_LONG   , DLOG_WARN,  true, "\033[33;1m[ 03-14 23:22:51.451 W/DLOG_ERROR_NOTAG P 4228, T 4567]\n\033[0m"
 487                                                    "DLOG_ERROR_NOMSG\n\n"                                                     },
 488         };
 489         CHECK_LOGPRINT_TESTCASES("\0\0GARBAGE", tests_garbage);
 490
 491         static const struct logprint_test_case tests_only_one_zero[] = {
 492                 {FORMAT_BRIEF  , DLOG_INFO, false, "I/THIS_IS_WEIRD( 4228): DLOG_ERROR_NOMSG\n"                               },
 493                 {FORMAT_RAW    , DLOG_INFO, false, "DLOG_ERROR_NOMSG\n"                                                       },
 494                 {FORMAT_PROCESS, DLOG_INFO, false, "I( 4228) DLOG_ERROR_NOMSG  (THIS_IS_WEIRD)\n"                             },
 495                 {FORMAT_LONG   , DLOG_INFO, false, "[ 03-14 23:22:51.451 I/THIS_IS_WEIRD P 4228, T 4567]\n"
 496                                                    "DLOG_ERROR_NOMSG\n\n"                                                     },
 497
 498                 {FORMAT_BRIEF  , DLOG_WARN,  true, "\033[33;1mW/THIS_IS_WEIRD( 4228): \033[0mDLOG_ERROR_NOMSG\n"              },
 499                 {FORMAT_RAW    , DLOG_WARN,  true, "DLOG_ERROR_NOMSG\n"                                                       },
 500                 {FORMAT_PROCESS, DLOG_WARN,  true, "\033[33;1mW( 4228) \033[0mDLOG_ERROR_NOMSG\033[33;1m  "
 501                                                    "(THIS_IS_WEIRD)\n\033[0m"},
 502                 {FORMAT_LONG   , DLOG_WARN,  true, "\033[33;1m[ 03-14 23:22:51.451 W/THIS_IS_WEIRD P 4228, T 4567]\n\033[0m"
 503                                                    "DLOG_ERROR_NOMSG\n\n"                                                     },
 504         };
 505         CHECK_LOGPRINT_TESTCASES("THIS_IS_WEIRD", tests_only_one_zero);
 506
 507         static const struct logprint_test_case tests_fixup_pipe[] = {
 508                 // formats using the SENT timestamp (nominally)
 509                 {FORMAT_TIME         , DLOG_INFO, false, "02-01 00:05:17.734+0000 I/BASIC TAG(    0): Basic message.\n"
 510                                                          "02-01 00:05:17.734+0000 I/BASIC TAG(    0): [dlog inline warning: modified invalid timestamp]\n"              },
 511                 {FORMAT_LONG         , DLOG_INFO, false, "[ 02-01 00:05:17.734 I/BASIC TAG P    0, T    0]\n"
 512                                                          "Basic message.\n"
 513                                                          "[dlog inline warning: modified invalid timestamp]\n\n"                                                        },
 514                 {FORMAT_THREADTIME   , DLOG_INFO, false, "02-01 00:05:17.734+0000 I/BASIC TAG (P    0, T    0): Basic message.\n"
 515                                                          "02-01 00:05:17.734+0000 I/BASIC TAG (P    0, T    0): [dlog inline warning: modified invalid timestamp]\n"    },
 516                 {FORMAT_KERNELTIME   , DLOG_INFO, false, "365467.346 I/BASIC TAG(P    0, T    0): Basic message.\n"
 517                                                          "365467.346 I/BASIC TAG(P    0, T    0): [dlog inline warning: modified invalid timestamp]\n"                  },
 518
 519                 // formats using the RECV timestamp
 520                 {FORMAT_RECV_REALTIME, DLOG_INFO, false, "02-01 00:05:17.734 I/BASIC TAG(P    0, T    0): Basic message.\n"
 521                                                          "02-01 00:05:17.734 I/BASIC TAG(P    0, T    0): [dlog inline warning: modified invalid timestamp]\n"          },
 522                 {FORMAT_RWTIME       , DLOG_INFO, false, "02-01 00:05:17 [365467.346] I/BASIC TAG(P    0, T    0): Basic message.\n"
 523                                                          "02-01 00:05:17 [365467.346] I/BASIC TAG(P    0, T    0): [dlog inline warning: modified invalid timestamp]\n" },
 524
 525                 // formats without a timestamp
 526                 {FORMAT_BRIEF        , DLOG_INFO, false, "I/BASIC TAG(    0): Basic message.\n"
 527                                                          "I/BASIC TAG(    0): [dlog inline warning: modified invalid timestamp]\n"                                      },
 528                 {FORMAT_PROCESS      , DLOG_INFO, false, "I(    0) Basic message.  (BASIC TAG)\n"
 529                                                          "I(    0) [dlog inline warning: modified invalid timestamp]  (BASIC TAG)\n"                                    },
 530                 {FORMAT_TAG          , DLOG_INFO, false, "I/BASIC TAG: Basic message.\n"
 531                                                          "I/BASIC TAG: [dlog inline warning: modified invalid timestamp]\n"                                             },
 532                 {FORMAT_THREAD       , DLOG_INFO, false, "I(P    0, T    0) Basic message.\n"
 533                                                          "I(P    0, T    0) [dlog inline warning: modified invalid timestamp]\n"                                        },
 534                 {FORMAT_RAW          , DLOG_INFO, false, "Basic message.\n"
 535                                                          "[dlog inline warning: modified invalid timestamp]\n"                                                          },
 536                 // JSON
 537                 {FORMAT_JSON         , DLOG_INFO, false, "{"
 538                         "\"priority\":\"info\","
 539                         "\"pid\":0,"
 540                         "\"tid\":0,"
 541                         "\"recv_real\":\"1970-02-01T00:05:17+0000\","
 542                         "\"recv_mono\":365467.346253662,"
 543                         "\"sent_real\":\"1970-02-01T00:05:17+0000\","
 544                         "\"sent_mono\":365467.346253662,"
 545                         "\"tag\":\"BASIC TAG\","
 546                         "\"msg\":\"Basic message.\\n"
 547                                   "[dlog inline warning: modified invalid timestamp]\""
 548                 "}\n" },
 549         };
 550         CHECK_LOGPRINT_TESTCASES_INVALID("BASIC TAG\0Basic message.", tests_fixup_pipe);
 551 }
 552
 553 void check_log_print_log_line_buffer(void)
 554 {
 555         struct dlogutil_entry_with_msg entry;
 556         const char tag_msg[] = "tag\0msg";
 557         const char msg[] = "msg\n";
 558         standard_test_msg(&entry, tag_msg, sizeof(tag_msg));
 559
 560         char data[1234];
 561         struct log_write_buffer wbuf = {
 562                 .data = data,
 563                 .position = 0,
 564                 .size = sizeof(data),
 565         };
 566
 567         fake_write = true;
 568         buffer[0] = '\0';
 569
 570         for (int cpos = 0; cpos < sizeof(data); cpos += strlen(msg)) {
 571                 assert(wbuf.position == cpos);
 572                 assert(strlen(buffer) == 0);
 573                 assert(log_print_log_line((struct log_format){
 574                         .format = FORMAT_RAW,
 575                         .color = false,
 576                 }, 0, &entry.header, &wbuf) == 1);
 577         }
 578
 579         assert(wbuf.position == strlen(msg));
 580         assert(memcmp(wbuf.data, msg, strlen(msg)) == 0);
 581
 582         int total_count = sizeof(data) / strlen(msg);
 583         assert(strlen(buffer) == total_count * strlen(msg));
 584         for (int i = 0; i < total_count; ++i)
 585                 assert(memcmp(buffer + i * strlen(msg), msg, strlen(msg)) == 0);
 586
 587         fake_write = false;
 588 }
 589
 590 char *json_escape_string(char *in);
 591 void check_json_escape_string_testcase(char *in, char *correct)
 592 {
 593         char *out = json_escape_string(in);
 594         assert(out);
 595         assert(!strcmp(out, correct));
 596         free(out);
 597 }
 598
 599 enum ts_type {
 600         TS_SENT,
 601         TS_RECV,
 602 };
 603 const char *json_priority_name(log_priority prio);
 604 struct timespec entry_get_ts(const dlogutil_entry_s *entry, bool sent, bool mono);
 605 char *log_format_json(char *default_buffer, size_t default_buffer_size, const dlogutil_entry_s *entry, size_t *p_outLength, char *tag, char *msg);
 606 void check_json(void)
 607 {
 608         // TODO: Failure testing
 609         check_json_escape_string_testcase("abc/def", "abc/def");
 610         check_json_escape_string_testcase("\x01\x02\x03", "\\u0001\\u0002\\u0003");
 611         check_json_escape_string_testcase("\x1A\x1B\x1C", "\\u001A\\u001B\\u001C");
 612         check_json_escape_string_testcase("\x1D\x1E\x1F", "\\u001D\\u001E\\u001F");
 613         check_json_escape_string_testcase("\"\\\b\f\n\r\t", "\\\"\\\\\\b\\f\\n\\r\\t");
 614         check_json_escape_string_testcase("zażółć gęślą jaźń", "zażółć gęślą jaźń");
 615         check_json_escape_string_testcase("삼성", "삼성");
 616         check_json_escape_string_testcase("タイゼン", "タイゼン");
 617         check_json_escape_string_testcase("🏀", "🏀");
 618
 619         assert(!strcmp(json_priority_name(DLOG_VERBOSE), "verbose"));
 620         assert(!strcmp(json_priority_name(DLOG_DEBUG),   "debug"));
 621         assert(!strcmp(json_priority_name(DLOG_INFO),    "info"));
 622         assert(!strcmp(json_priority_name(DLOG_WARN),    "warning"));
 623         assert(!strcmp(json_priority_name(DLOG_ERROR),   "error"));
 624         assert(!strcmp(json_priority_name(DLOG_FATAL),   "fatal"));
 625         assert(!strcmp(json_priority_name(DLOG_SILENT),  "silent"));
 626         assert(!strcmp(json_priority_name(DLOG_UNKNOWN), "unknown"));
 627         assert(!strcmp(json_priority_name(123),          "unknown"));
 628
 629         char data[] = "tag\0important message";
 630         dlogutil_entry_s *ent = calloc(1, sizeof(*ent) + sizeof data);
 631         assert(ent);
 632         ent->len = sizeof data;
 633         ent->tag_len = 3;
 634         strncpy(ent->msg, data, ent->len);
 635         ent->priority = DLOG_DEBUG;
 636         ent->pid = 17;
 637         ent->tid = 18;
 638
 639         struct timespec ts;
 640
 641 #define TEST_EMPTY_TIMESTAMP() \
 642         ent->nsec_sent_mono = ent->nsec_recv_mono = ent->nsec_sent_real = ent->nsec_recv_real = -1; \
 643         ts = entry_get_ts(ent, CURRENT_SENT, CURRENT_MONO); \
 644         assert(ts.tv_sec == 0); \
 645         assert(ts.tv_nsec == 0)
 646 #define TEST_SINGLE_TIMESTAMP(which, to_set, expected) \
 647         ent->sec_##which = ent->nsec_##which = to_set; \
 648         ts = entry_get_ts(ent, CURRENT_SENT, CURRENT_MONO); \
 649         assert(ts.tv_sec == expected); \
 650         assert(ts.tv_nsec == expected)
 651
 652  #define CURRENT_MONO true
 653   #define CURRENT_SENT true
 654         TEST_EMPTY_TIMESTAMP();
 655         TEST_SINGLE_TIMESTAMP(recv_real, 1, 1);
 656         TEST_SINGLE_TIMESTAMP(sent_real, 2, 2);
 657         TEST_SINGLE_TIMESTAMP(recv_mono, 3, 3);
 658         TEST_SINGLE_TIMESTAMP(sent_mono, 4, 4);
 659   #undef CURRENT_SENT
 660
 661   #define CURRENT_SENT false
 662         TEST_EMPTY_TIMESTAMP();
 663         TEST_SINGLE_TIMESTAMP(sent_real, 1, 1);
 664         TEST_SINGLE_TIMESTAMP(recv_real, 2, 2);
 665         TEST_SINGLE_TIMESTAMP(sent_mono, 3, 3);
 666         TEST_SINGLE_TIMESTAMP(recv_mono, 4, 4);
 667   #undef CURRENT_SENT
 668  #undef CURRENT_MONO
 669
 670  #define CURRENT_MONO false
 671   #define CURRENT_SENT true
 672         TEST_EMPTY_TIMESTAMP();
 673         TEST_SINGLE_TIMESTAMP(recv_mono, 1, 0);
 674         TEST_SINGLE_TIMESTAMP(sent_mono, 2, 0);
 675         TEST_SINGLE_TIMESTAMP(recv_real, 3, 3);
 676         TEST_SINGLE_TIMESTAMP(sent_real, 4, 4);
 677   #undef CURRENT_SENT
 678
 679   #define CURRENT_SENT false
 680         TEST_EMPTY_TIMESTAMP();
 681         TEST_SINGLE_TIMESTAMP(sent_mono, 1, 0);
 682         TEST_SINGLE_TIMESTAMP(recv_mono, 2, 0);
 683         TEST_SINGLE_TIMESTAMP(sent_real, 3, 3);
 684         TEST_SINGLE_TIMESTAMP(recv_real, 4, 4);
 685   #undef CURRENT_SENT
 686  #undef CURRENT_MONO
 687
 688 #undef TEST_EMPTY_TIMESTAMP
 689 #undef TEST_SINGLE_TIMESTAMP
 690
 691         char buf[512] = {};
 692         size_t out_len;
 693
 694         ent->nsec_sent_mono = ent->nsec_recv_mono = ent->nsec_sent_real = ent->nsec_recv_real = -1;
 695         assert(log_format_json(buf, sizeof(buf), ent, &out_len, "tag", "message") == buf);
 696         assert(strlen(buf) == out_len);
 697         assert(!strcmp(buf, "{" \
 698                 "\"priority\":\"debug\"," \
 699                 "\"pid\":17," \
 700                 "\"tid\":18," \
 701                 "\"tag\":\"tag\"," \
 702                 "\"msg\":\"message\"" \
 703         "}\n"));
 704
 705         char *target;
 706         target = log_format_json(NULL, out_len, ent, &out_len, "tag", "message");
 707         assert(target);
 708         assert(target != buf);
 709         assert(strlen(target) == out_len);
 710         assert(!strcmp(buf, target));
 711         free(target);
 712
 713         ent->sec_sent_mono = ent->nsec_sent_mono = 21;
 714         ent->sec_recv_mono = ent->nsec_recv_mono = 22;
 715         ent->sec_sent_real = ent->nsec_sent_real = 23242527;
 716         ent->sec_recv_real = ent->nsec_recv_real = 28293031;
 717         assert(log_format_json(buf, sizeof(buf), ent, &out_len, "tag", "message") == buf);
 718         assert(strlen(buf) == out_len);
 719         assert(!strcmp(buf, "{"\
 720                 "\"priority\":\"debug\","\
 721                 "\"pid\":17,"\
 722                 "\"tid\":18,"\
 723                 "\"recv_real\":\"1970-11-24T11:10:31+0000\","\
 724                 "\"recv_mono\":22.000000022,"\
 725                 "\"sent_real\":\"1970-09-27T00:15:27+0000\","\
 726                 "\"sent_mono\":21.000000021,"\
 727                 "\"tag\":\"tag\","\
 728                 "\"msg\":\"message\""\
 729         "}\n"));
 730
 731         char data2[] = "∫\0\x01\x02\x03\x14\x15\x16\"\\\b\f\n\r\t🤔";
 732         assert(sizeof data == sizeof data2);
 733         strncpy(ent->msg, data2, ent->len);
 734         assert(log_format_json(buf, sizeof(buf), ent, &out_len, "∫", "\x01\x02\x03\x14\x15\x16\"\\\b\f\n\r\t🤔") == buf);
 735         assert(strlen(buf) == out_len);
 736         assert(!strcmp(buf, "{"\
 737                 "\"priority\":\"debug\","\
 738                 "\"pid\":17,"\
 739                 "\"tid\":18,"\
 740                 "\"recv_real\":\"1970-11-24T11:10:31+0000\","\
 741                 "\"recv_mono\":22.000000022,"\
 742                 "\"sent_real\":\"1970-09-27T00:15:27+0000\","\
 743                 "\"sent_mono\":21.000000021,"\
 744                 "\"tag\":\"∫\","\
 745                 "\"msg\":\"\\u0001\\u0002\\u0003\\u0014\\u0015\\u0016\\\"\\\\\\b\\f\\n\\r\\t🤔\""\
 746         "}\n"));
 747
 748         free(ent);
 749 }
 750
 751 void check_utf8_correctness(void)
 752 {
 753         /* © is two bytes */
 754         static const struct logprint_test_case test_2_bytes_0_shift[] = {
 755                 {FORMAT_KERNELTIME, DLOG_INFO, false,
 756                         "3205048.235 I/©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©foo1\n"},
 757                 {FORMAT_PROCESS, DLOG_INFO, false,
 758                         "I( 4228) foo1  (©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©"},
 759         };
 760         CHECK_LOGPRINT_TESTCASES("©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©\0foo1", test_2_bytes_0_shift);
 761         static const struct logprint_test_case test_2_bytes_1_shift[] = {
 762                 {FORMAT_KERNELTIME, DLOG_INFO, false,
 763                         "3205048.235 I/1©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©foo1\n"},
 764                 {FORMAT_PROCESS, DLOG_INFO, false,
 765                         "I( 4228) foo1  (1©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©"},
 766         };
 767         CHECK_LOGPRINT_TESTCASES("1©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©©\0foo1", test_2_bytes_1_shift);
 768
 769         /* ♘ is three bytes */
 770         static const struct logprint_test_case test_3_bytes_0_shift[] = {
 771                 {FORMAT_KERNELTIME, DLOG_INFO, false,
 772                         "3205048.235 I/♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘foo1\n"},
 773                 {FORMAT_PROCESS, DLOG_INFO, false,
 774                         "I( 4228) foo1  (♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘"},
 775         };
 776         CHECK_LOGPRINT_TESTCASES("♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘\0foo1", test_3_bytes_0_shift);
 777         static const struct logprint_test_case test_3_bytes_1_shift[] = {
 778                 {FORMAT_KERNELTIME, DLOG_INFO, false,
 779                         "3205048.235 I/1♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘foo1\n"},
 780                 {FORMAT_PROCESS, DLOG_INFO, false,
 781                         "I( 4228) foo1  (1♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘"},
 782         };
 783         CHECK_LOGPRINT_TESTCASES("1♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘\0foo1", test_3_bytes_1_shift);
 784         static const struct logprint_test_case test_3_bytes_2_shift[] = {
 785                 {FORMAT_KERNELTIME, DLOG_INFO, false,
 786                         "3205048.235 I/12♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘foo1\n"},
 787                 {FORMAT_PROCESS, DLOG_INFO, false,
 788                         "I( 4228) foo1  (12♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘"},
 789         };
 790         CHECK_LOGPRINT_TESTCASES("12♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘♘\0foo1", test_3_bytes_2_shift);
 791
 792         /* 💯 is four bytes */
 793         static const struct logprint_test_case test_4_bytes_0_shift[] = {
 794                 {FORMAT_KERNELTIME, DLOG_INFO, false,
 795                         "3205048.235 I/💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯foo1\n"},
 796                 {FORMAT_PROCESS, DLOG_INFO, false,
 797                         "I( 4228) foo1  (💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯"},
 798         };
 799         CHECK_LOGPRINT_TESTCASES("💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯\0foo1", test_4_bytes_0_shift);
 800         static const struct logprint_test_case test_4_bytes_1_shift[] = {
 801                 {FORMAT_KERNELTIME, DLOG_INFO, false,
 802                         "3205048.235 I/1💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯foo1\n"},
 803                 {FORMAT_PROCESS, DLOG_INFO, false,
 804                         "I( 4228) foo1  (1💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯"},
 805         };
 806         CHECK_LOGPRINT_TESTCASES("1💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯\0foo1", test_4_bytes_1_shift);
 807         static const struct logprint_test_case test_4_bytes_2_shift[] = {
 808                 {FORMAT_KERNELTIME, DLOG_INFO, false,
 809                         "3205048.235 I/12💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯foo1\n"},
 810                 {FORMAT_PROCESS, DLOG_INFO, false,
 811                         "I( 4228) foo1  (12💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯"},
 812         };
 813         CHECK_LOGPRINT_TESTCASES("12💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯\0foo1", test_4_bytes_2_shift);
 814         static const struct logprint_test_case test_4_bytes_3_shift[] = {
 815                 {FORMAT_KERNELTIME, DLOG_INFO, false,
 816                         "3205048.235 I/123💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯foo1\n"},
 817                 {FORMAT_PROCESS, DLOG_INFO, false,
 818                         "I( 4228) foo1  (123💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯"},
 819         };
 820         CHECK_LOGPRINT_TESTCASES("123💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯💯\0foo1", test_4_bytes_3_shift);
 821 }
 822
 823 void check_syscall_failure_handling(void)
 824 {
 825         struct log_filter *const filter = log_filter_new();
 826         assert(filter);
 827         assert(!log_filter_set_tid(filter, 123));
 828         assert(!log_filter_set_pid(filter, 456));
 829         assert(!log_add_filter_rule(filter, "FOO:E"));
 830
 831         struct log_filter *const clone = log_filter_from_filter(filter);
 832         assert(clone);
 833         log_filter_free(clone);
 834
 835         fail_alloc = true;
 836         assert(!log_filter_new());
 837         assert(!log_filter_from_filter(filter));
 838         assert(TIZEN_ERROR_OUT_OF_MEMORY == log_filter_set_tid(filter, 123));
 839         assert(TIZEN_ERROR_OUT_OF_MEMORY == log_filter_set_pid(filter, 456));
 840         fail_alloc = false;
 841
 842         // Not really a syscall, but eh
 843         fail_list_add = true;
 844         assert(TIZEN_ERROR_OUT_OF_MEMORY == log_add_filter_rule(filter, "FOO:E"));
 845         fail_list_add = false;
 846
 847         fail_strdup = true;
 848         assert(!log_filter_from_filter(filter));
 849         assert(TIZEN_ERROR_OUT_OF_MEMORY == log_filter_set_filterspec(filter, "FOO:E"));
 850         assert(TIZEN_ERROR_OUT_OF_MEMORY == log_add_filter_rule(filter, "FOO:E"));
 851         fail_strdup = false;
 852
 853         fail_strndup = true; // N
 854         assert(TIZEN_ERROR_OUT_OF_MEMORY == log_filter_set_filterspec(filter, "FOO:E"));
 855         fail_strndup = false;
 856
 857         /* the array size is an arbitrary value between 512, i.e. the size of the default buffer,
 858          * and 4096, i.e. LOG_MAX_PAYLOAD_SIZE (higher should also work but would be pointless). */
 859         char msg[666] = {
 860                 [0 ... 41] = 'A', // tag
 861                 [42] = '\0',
 862                 [43 ... sizeof msg - 2] = 'a',  // msg
 863                 [sizeof msg - 1] = '\0'
 864         };
 865         struct dlogutil_entry_with_msg entry;
 866         standard_test_msg(&entry, msg, sizeof msg);
 867
 868         struct log_format format = {
 869                         .format = FORMAT_TIME,
 870                         .color = false,
 871         };
 872
 873         fail_alloc = true;
 874         assert(-1 == log_print_log_line(format, 0, &entry.header, &(struct log_write_buffer) { }));
 875         fail_alloc = false;
 876
 877         fail_localtime_r = true;
 878         assert(-1 == log_print_log_line(format, 0, &entry.header, &(struct log_write_buffer) { }));
 879         fail_localtime_r = false;
 880
 881         partial_write = -1;
 882         assert(0 == log_print_log_line(format, 0, &entry.header, &(struct log_write_buffer) { }));
 883
 884         partial_write = 17;
 885         assert(1 == log_print_log_line(format, 0, &entry.header, &(struct log_write_buffer) { }));
 886
 887         partial_write = 0;
 888         log_filter_free(filter);
 889 }
 890
 891 void check_invalid_input(void)
 892 {
 893         const dlogutil_entry_s entry = { .len = 1 };
 894         const char *data;
 895
 896         assert(dlogutil_entry_get_message(&entry, &data) == TIZEN_ERROR_NO_DATA);
 897         assert(!data);
 898
 899         assert(dlogutil_entry_get_tag(&entry, &data) == TIZEN_ERROR_NO_DATA);
 900         assert(!data);
 901
 902         struct log_filter *const filter = log_filter_new();
 903         assert(filter);
 904         assert(TIZEN_ERROR_INVALID_PARAMETER == log_add_filter_rule(filter, ":D")); // >mfw tagless rule gets processed correctly
 905         log_filter_free(filter);
 906 }
 907
 908 void check_log_format_from_string(void)
 909 {
 910         static const struct {
 911                 char const *string;
 912                 log_print_format format;
 913         } expected_formats[] = {
 914                 {"brief"          , FORMAT_BRIEF     },
 915                 {"  brief"        , FORMAT_OFF       },
 916                 {"tag"            , FORMAT_TAG       },
 917                 {"tagging up turf", FORMAT_OFF       },
 918                 {"process"        , FORMAT_PROCESS   },
 919                 {"long"           , FORMAT_LONG      },
 920                 {"thien long"     , FORMAT_OFF       },
 921                 {"threadtime"     , FORMAT_THREADTIME},
 922                 {"kerneltime"     , FORMAT_KERNELTIME},
 923                 {"hammertime"     , FORMAT_OFF       },
 924         };
 925
 926         for (size_t i = 0; i < NELEMS(expected_formats); ++i)
 927                 assert(log_format_from_string(expected_formats[i].string) == expected_formats[i].format);
 928 }
 929
 930 void check_get_format_sorting(void)
 931 {
 932         static const struct {
 933                 log_print_format format;
 934                 dlogutil_sorting_order_e sorting;
 935         } expected_sorting[] = {
 936                 {FORMAT_TAG          , DLOGUTIL_SORT_DEFAULT  },
 937                 {FORMAT_PROCESS      , DLOGUTIL_SORT_DEFAULT  },
 938                 {FORMAT_THREAD       , DLOGUTIL_SORT_DEFAULT  },
 939                 {FORMAT_RAW          , DLOGUTIL_SORT_DEFAULT  },
 940                 {FORMAT_BRIEF        , DLOGUTIL_SORT_DEFAULT  },
 941                 {FORMAT_TIME         , DLOGUTIL_SORT_SENT_REAL},
 942                 {FORMAT_THREADTIME   , DLOGUTIL_SORT_SENT_REAL},
 943                 {FORMAT_KERNELTIME   , DLOGUTIL_SORT_SENT_MONO},
 944                 {FORMAT_LONG         , DLOGUTIL_SORT_SENT_REAL},
 945                 {FORMAT_RWTIME       , DLOGUTIL_SORT_RECV_REAL},
 946                 {FORMAT_RECV_REALTIME, DLOGUTIL_SORT_RECV_REAL},
 947         };
 948
 949         for (size_t i = 0; i < NELEMS(expected_sorting); ++i) {
 950                 assert(get_format_sorting(expected_sorting[i].format) == expected_sorting[i].sorting);
 951         }
 952 }
 953
 954 void check_filter_pri_to_char(void)
 955 {
 956         static const struct {
 957                 log_priority pri;
 958                 char c;
 959         } convertibles[] = {
 960                 {DLOG_VERBOSE    , 'V' },
 961                 {DLOG_DEBUG      , 'D' },
 962                 {DLOG_INFO       , 'I' },
 963                 {DLOG_WARN       , 'W' },
 964                 {DLOG_ERROR      , 'E' },
 965                 {DLOG_FATAL      , 'F' },
 966                 {DLOG_SILENT     , 'S' },
 967         }, expected_pris[] = {
 968                 {DLOG_UNKNOWN    , '0' },
 969                 {DLOG_DEFAULT    , '1' },
 970                 {DLOG_VERBOSE    , '2' },
 971                 {DLOG_DEBUG      , '3' },
 972                 {DLOG_INFO       , '4' },
 973                 {DLOG_WARN       , '5' },
 974                 {DLOG_ERROR      , '6' },
 975                 {DLOG_FATAL      , '7' },
 976                 {DLOG_VERBOSE    , '8' }, // makes little sense but ok
 977                 {DLOG_VERBOSE    , '9' }, // ditto
 978
 979                 {DLOG_VERBOSE    , 'v' },
 980                 {DLOG_DEBUG      , 'd' },
 981                 {DLOG_INFO       , 'i' },
 982                 {DLOG_WARN       , 'w' },
 983                 {DLOG_ERROR      , 'e' },
 984                 {DLOG_FATAL      , 'f' },
 985                 {DLOG_SILENT     , 's' },
 986                 {DLOG_DEFAULT    , '*' },
 987
 988                 {DLOG_UNKNOWN    , 'l' },
 989                 {DLOG_UNKNOWN    , 'L' },
 990                 {DLOG_UNKNOWN    , ' ' },
 991                 {DLOG_UNKNOWN    , '\a'},
 992                 {DLOG_UNKNOWN    , '\0'},
 993         }, expected_chars[] = {
 994                 {DLOG_DEFAULT    , '?' },
 995                 {DLOG_UNKNOWN    , '?' },
 996                 {(log_priority)42, '?' },
 997                 {(log_priority)-9, '?' },
 998         };
 999
1000         for (size_t i = 0; i < NELEMS(convertibles); ++i) {
1001                 assert(filter_pri_to_char(convertibles[i].pri) == convertibles[i].c);
1002                 assert(filter_char_to_pri(convertibles[i].c) == convertibles[i].pri);
1003         }
1004
1005         for (size_t i = 0; i < NELEMS(expected_pris); ++i)
1006                 assert(filter_char_to_pri(expected_pris[i].c) == expected_pris[i].pri);
1007
1008         for (size_t i = 0; i < NELEMS(expected_chars); ++i)
1009                 assert(filter_pri_to_char(expected_chars[i].pri) == expected_chars[i].c);
1010 }
1011
1012 void log_filter_default(void)
1013 {
1014         struct log_filter *const filter = log_filter_new();
1015         bool ret = log_filter_need_apply_default(filter);
1016         assert(ret);
1017         log_filter_free(filter);
1018 }
1019
1020 int main(void)
1021 {
1022         check_log_format_from_string();
1023         check_get_format_sorting();
1024         check_filter_pri_to_char();
1025         check_log_print_log_line();
1026         check_log_print_log_line_buffer();
1027         check_invalid_input();
1028         check_syscall_failure_handling();
1029         check_utf8_correctness();
1030         check_json();
1031         log_filter_default();
1032 }