1 /* _XOPEN_SOURCE >= 500 for vsnprintf() */ 2 #ifndef _XOPEN_SOURCE 3 #define _XOPEN_SOURCE 700 4 #endif 5 6 #include "first.h" 7 8 #include "log.h" 9 10 #include <sys/types.h> 11 #include "sys-time.h" 12 #include <errno.h> 13 #include <string.h> 14 #include <stdarg.h> 15 #include <stdio.h> /* vsnprintf() */ 16 #include <stdlib.h> /* malloc() free() */ 17 #include <unistd.h> 18 19 #ifdef HAVE_SYSLOG_H 20 # include <syslog.h> 21 #endif 22 23 #include "ck.h" 24 #include "fdlog.h" 25 26 static fdlog_st log_stderrh = { FDLOG_FD, STDERR_FILENO, { NULL, 0, 0 }, NULL }; 27 static fdlog_st *log_errh = &log_stderrh; 28 static unix_time64_t log_tlast = 0; 29 30 /* log_con_jqueue instance here to be defined in shared object (see base.h) */ 31 connection *log_con_jqueue; 32 33 unix_time64_t log_epoch_secs = 0; 34 unix_time64_t log_monotonic_secs = 0; 35 36 #if !defined(HAVE_CLOCK_GETTIME) || !HAS_TIME_BITS64 37 38 int log_clock_gettime (const int clockid, unix_timespec64_t * const ts) { 39 #ifdef HAVE_CLOCK_GETTIME 40 #if HAS_TIME_BITS64 41 return clock_gettime(clockid, ts); 42 #else 43 struct timespec ts32; 44 int rc = clock_gettime(clockid, &ts32); 45 if (0 == rc) { 46 /*(treat negative 32-bit tv.tv_sec as unsigned)*/ 47 ts->tv_sec = TIME64_CAST(ts32.tv_sec); 48 ts->tv_nsec = ts32.tv_nsec; 49 } 50 return rc; 51 #endif 52 #else 53 /* Mac OSX before 10.12 Sierra does not provide clock_gettime() 54 * e.g. defined(__APPLE__) && defined(__MACH__) 55 * && __ENVIRONMENT_MAC_OS_X_VERSION_MIN_REQUIRED__ < 101200 */ 56 struct timeval tv; 57 gettimeofday(&tv, NULL); 58 UNUSED(clockid); 59 #if HAS_TIME_BITS64 60 ts->tv_sec = tv.tv_sec; 61 #else /*(treat negative 32-bit tv.tv_sec as unsigned)*/ 62 ts->tv_sec = TIME64_CAST(tv.tv_sec); 63 #endif 64 ts->tv_nsec = tv.tv_usec * 1000; 65 return 0; 66 #endif 67 } 68 69 int log_clock_gettime_realtime (unix_timespec64_t *ts) { 70 #ifdef HAVE_CLOCK_GETTIME 71 return log_clock_gettime(CLOCK_REALTIME, ts); 72 #else 73 return log_clock_gettime(0, ts); 74 #endif 75 } 76 77 #endif /* !defined(HAVE_CLOCK_GETTIME) || !HAS_TIME_BITS64 */ 78 79 80 /* retry write on EINTR or when not all data was written */ 81 ssize_t write_all(int fd, const void * const buf, size_t count) { 82 ssize_t written = 0; 83 ssize_t wr; 84 85 do { 86 wr = write(fd, (const char *)buf + written, count); 87 } while (wr > 0 ? (written += wr, count -= wr) : wr < 0 && errno == EINTR); 88 89 if (__builtin_expect( (0 == count), 1)) 90 return written; 91 else { 92 if (0 == wr) errno = EIO; /* really shouldn't happen... */ 93 return -1; /* fail - repeating probably won't help */ 94 } 95 } 96 97 98 __attribute_nonnull__() 99 static void 100 log_buffer_timestamp (buffer * const restrict b) 101 { 102 if (-2 == log_tlast) { /* -2 is value to flag high-precision timestamp */ 103 unix_timespec64_t ts = { 0, 0 }; 104 log_clock_gettime_realtime(&ts); 105 #if 0 106 buffer_append_int(b, TIME64_CAST(ts.tv_sec)); 107 #else /*(closer to syslog time format RFC 3339)*/ 108 struct tm tm; 109 buffer_append_strftime(b, "%F %T", 110 localtime64_r(&ts.tv_sec, &tm)); 111 #endif 112 buffer_append_string_len(b, CONST_STR_LEN(".000000000: ")); 113 char n[LI_ITOSTRING_LENGTH]; 114 const size_t nlen = 115 li_utostrn(n, sizeof(n), (unsigned long)ts.tv_nsec); 116 memcpy(b->ptr+buffer_clen(b)-nlen-2, n, nlen); 117 } 118 else { 119 /* cache the generated timestamp */ 120 static uint32_t tlen; 121 static char tstr[24]; /* 20 "%F %T" incl '\0' +2 ": " */ 122 if (__builtin_expect( (log_tlast != log_epoch_secs), 0)) { 123 struct tm tm; 124 log_tlast = log_epoch_secs; 125 tlen = (uint32_t) 126 strftime(tstr, sizeof(tstr), "%F %T", 127 localtime64_r(&log_tlast, &tm)); 128 tstr[ tlen] = ':'; 129 tstr[++tlen] = ' '; 130 /*tstr[++tlen] = '\0';*//*(not necessary for our use)*/ 131 ++tlen; 132 } 133 134 buffer_copy_string_len(b, tstr, tlen); 135 } 136 } 137 138 139 __attribute_nonnull__() 140 static void 141 log_buffer_prefix (buffer * const restrict b, 142 const char * const restrict filename, 143 const unsigned int line) 144 { 145 char lstr[LI_ITOSTRING_LENGTH]; 146 struct const_iovec iov[] = { 147 { CONST_STR_LEN("(") } 148 ,{ filename, strlen(filename) } 149 ,{ CONST_STR_LEN(".") } 150 ,{ lstr, li_itostrn(lstr, sizeof(lstr), line) } 151 ,{ CONST_STR_LEN(") ") } 152 }; 153 buffer_append_iovec(b, iov, sizeof(iov)/sizeof(*iov)); 154 } 155 156 157 static void 158 log_buffer_append_encoded (buffer * const b, 159 const char * const s, const size_t n) 160 { 161 size_t i; 162 for (i = 0; i < n && ' ' <= s[i] && s[i] <= '~'; ++i) ;/*(ASCII isprint())*/ 163 if (i == n) 164 buffer_append_string_len(b, s, n); /* common case; nothing to encode */ 165 else 166 buffer_append_string_c_escaped(b, s, n); 167 } 168 169 170 __attribute_format__((__printf__, 2, 0)) 171 __attribute_nonnull__() 172 static void 173 log_buffer_vsprintf (buffer * const restrict b, 174 const char * const restrict fmt, va_list ap) 175 { 176 /* NOTE: log_buffer_prefix() ensures 0 != b->used */ 177 /*assert(0 != b->used);*//*(only because code calcs below assume this)*/ 178 /*assert(0 != b->size);*//*(b has non-size after log_buffer_prefix())*/ 179 size_t blen = buffer_clen(b); 180 size_t bsp = buffer_string_space(b)+1; 181 char *s = b->ptr + blen; 182 size_t n; 183 184 va_list aptry; 185 va_copy(aptry, ap); 186 n = (size_t)vsnprintf(s, bsp, fmt, aptry); 187 va_end(aptry); 188 189 if (n < bsp) 190 buffer_truncate(b, blen+n); /*buffer_commit(b, n);*/ 191 else { 192 s = buffer_extend(b, n); 193 vsnprintf(s, n+1, fmt, ap); 194 } 195 196 size_t i; 197 for (i = 0; i < n && ' ' <= s[i] && s[i] <= '~'; ++i) ;/*(ASCII isprint())*/ 198 if (i == n) return; /* common case; nothing to encode */ 199 200 /* need to encode log line 201 * copy original line fragment, append encoded line to buffer, free copy */ 202 char * const src = (char *)malloc(n); 203 ck_assert(src); 204 memcpy(src, s, n); /*(note: not '\0'-terminated)*/ 205 buffer_truncate(b, blen); 206 buffer_append_string_c_escaped(b, src, n); 207 free(src); 208 } 209 210 211 __attribute_nonnull__() 212 static buffer * 213 log_buffer_prepare (const log_error_st * const errh, 214 const char * const restrict filename, 215 const unsigned int line) 216 { 217 buffer * const restrict b = &log_errh->b; /*(use shared temp buffer)*/ 218 buffer_clear(b); 219 if (errh->mode != FDLOG_SYSLOG) { /*(syslog() generates its own timestamp)*/ 220 if (-1 == errh->fd) return NULL; 221 log_buffer_timestamp(b); 222 } 223 log_buffer_prefix(b, filename, line); 224 return b; 225 } 226 227 228 __attribute_nonnull__() 229 static void 230 log_error_write (const log_error_st * const errh, buffer * const restrict b) 231 { 232 if (errh->mode != FDLOG_SYSLOG) { /* FDLOG_FD FDLOG_FILE FDLOG_PIPE */ 233 buffer_append_char(b, '\n'); 234 write_all(errh->fd, BUF_PTR_LEN(b)); 235 } 236 else { 237 syslog(LOG_ERR, "%s", b->ptr); 238 } 239 } 240 241 242 __attribute_noinline__ 243 static void 244 log_error_append_strerror (buffer * const b, const int errnum) 245 { 246 char buf[1024]; 247 errno_t rc = ck_strerror_s(buf, sizeof(buf), errnum); 248 if (0 == rc || rc == ERANGE) 249 buffer_append_str2(b, CONST_STR_LEN(": "), buf, strlen(buf)); 250 } 251 252 253 __attribute_format__((__printf__, 4, 0)) 254 static void 255 log_error_va_list_impl (const log_error_st *errh, 256 const char * const restrict filename, 257 const unsigned int line, 258 const char * const restrict fmt, va_list ap, 259 const int perr) 260 { 261 const int errnum = errno; 262 263 if (NULL == errh) errh = log_errh; 264 buffer * const restrict b = log_buffer_prepare(errh, filename, line); 265 if (NULL == b) return; /*(errno not modified if errh->fd == -1)*/ 266 267 log_buffer_vsprintf(b, fmt, ap); 268 if (perr) 269 log_error_append_strerror(b, errnum); 270 271 log_error_write(errh, b); 272 273 buffer_clear(b); 274 errno = errnum; 275 } 276 277 278 void 279 log_error(log_error_st * const errh, 280 const char * const filename, const unsigned int line, 281 const char *fmt, ...) 282 { 283 va_list ap; 284 va_start(ap, fmt); 285 log_error_va_list_impl(errh, filename, line, fmt, ap, 0); 286 va_end(ap); 287 } 288 289 290 void 291 log_perror (log_error_st * const errh, 292 const char * const filename, const unsigned int line, 293 const char * const fmt, ...) 294 { 295 va_list ap; 296 va_start(ap, fmt); 297 log_error_va_list_impl(errh, filename, line, fmt, ap, 1); 298 va_end(ap); 299 } 300 301 302 void 303 log_error_multiline (log_error_st *errh, 304 const char * const restrict filename, 305 const unsigned int line, 306 const char * const restrict multiline, 307 const size_t len, 308 const char * const restrict fmt, ...) 309 { 310 if (0 == len) return; 311 312 const int errnum = errno; 313 314 if (NULL == errh) errh = log_errh; 315 buffer * const restrict b = log_buffer_prepare(errh, filename, line); 316 if (NULL == b) return; /*(errno not modified if errh->fd == -1)*/ 317 318 va_list ap; 319 va_start(ap, fmt); 320 log_buffer_vsprintf(b, fmt, ap); 321 va_end(ap); 322 323 const uint32_t prefix_len = buffer_clen(b); 324 const char * const end = multiline + len; 325 for (const char *pos = multiline; pos < end; ++pos) { 326 const char * const current_line = pos; 327 pos = strchr(pos, '\n'); 328 if (!pos) 329 pos = end; 330 size_t n = (size_t)(pos - current_line); 331 if (n && current_line[n-1] == '\r') --n; /*(skip "\r\n")*/ 332 buffer_truncate(b, prefix_len); 333 log_buffer_append_encoded(b, current_line, n); 334 log_error_write(errh, b); 335 } 336 337 buffer_clear(b); 338 errno = errnum; 339 } 340 341 342 log_error_st * 343 log_set_global_errh (log_error_st * const errh, const int ts_high_precision) 344 { 345 /* reset log_tlast 346 * -1 for cached timestamp to not match log_epoch_secs 347 * (e.g. if realtime clock init at 0) 348 * -2 for high precision timestamp */ 349 log_tlast = ts_high_precision ? -2 : -1; 350 351 buffer_free_ptr(&log_stderrh.b); 352 return (log_errh = errh ? errh : &log_stderrh); 353 } 354