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 unsigned int n; 183 184 va_list aptry; 185 va_copy(aptry, ap); 186 n = (unsigned int)vsnprintf(s, bsp, fmt, aptry); 187 va_end(aptry); 188 189 if ((int)n <= 0) 190 return; 191 if (n < bsp) 192 buffer_truncate(b, blen+n); /*buffer_commit(b, n);*/ 193 else { 194 s = buffer_extend(b, n); 195 vsnprintf(s, n+1, fmt, ap); 196 } 197 198 unsigned int i; 199 for (i = 0; i < n && ' ' <= s[i] && s[i] <= '~'; ++i) ;/*(ASCII isprint())*/ 200 if (i == n) return; /* common case; nothing to encode */ 201 202 /* need to encode log line 203 * copy original line fragment, append encoded line to buffer, free copy */ 204 n -= i; 205 char * const src = (char *)ck_malloc(n); 206 memcpy(src, s+i, n); /*(note: not '\0'-terminated)*/ 207 buffer_truncate(b, blen+i); 208 buffer_append_string_c_escaped(b, src, n); 209 free(src); 210 } 211 212 213 __attribute_nonnull__() 214 static buffer * 215 log_buffer_prepare (const log_error_st * const errh, 216 const char * const restrict filename, 217 const unsigned int line) 218 { 219 buffer * const restrict b = &log_errh->b; /*(use shared temp buffer)*/ 220 buffer_clear(b); 221 if (errh->mode != FDLOG_SYSLOG) { /*(syslog() generates its own timestamp)*/ 222 if (-1 == errh->fd) return NULL; 223 log_buffer_timestamp(b); 224 } 225 log_buffer_prefix(b, filename, line); 226 return b; 227 } 228 229 230 __attribute_nonnull__() 231 static void 232 log_error_write (const log_error_st * const errh, buffer * const restrict b) 233 { 234 if (errh->mode != FDLOG_SYSLOG) { /* FDLOG_FD FDLOG_FILE FDLOG_PIPE */ 235 buffer_append_char(b, '\n'); 236 write_all(errh->fd, BUF_PTR_LEN(b)); 237 } 238 else { 239 syslog(LOG_ERR, "%s", b->ptr); 240 } 241 } 242 243 244 __attribute_noinline__ 245 static void 246 log_error_append_strerror (buffer * const b, const int errnum) 247 { 248 char buf[1024]; 249 errno_t rc = ck_strerror_s(buf, sizeof(buf), errnum); 250 if (0 == rc || rc == ERANGE) 251 buffer_append_str2(b, CONST_STR_LEN(": "), buf, strlen(buf)); 252 } 253 254 255 __attribute_format__((__printf__, 4, 0)) 256 static void 257 log_error_va_list_impl (const log_error_st *errh, 258 const char * const restrict filename, 259 const unsigned int line, 260 const char * const restrict fmt, va_list ap, 261 const int perr) 262 { 263 const int errnum = errno; 264 265 if (NULL == errh) errh = log_errh; 266 buffer * const restrict b = log_buffer_prepare(errh, filename, line); 267 if (NULL == b) return; /*(errno not modified if errh->fd == -1)*/ 268 269 log_buffer_vsprintf(b, fmt, ap); 270 if (perr) 271 log_error_append_strerror(b, errnum); 272 273 log_error_write(errh, b); 274 275 buffer_clear(b); 276 errno = errnum; 277 } 278 279 280 void 281 log_error(log_error_st * const errh, 282 const char * const filename, const unsigned int line, 283 const char *fmt, ...) 284 { 285 va_list ap; 286 va_start(ap, fmt); 287 log_error_va_list_impl(errh, filename, line, fmt, ap, 0); 288 va_end(ap); 289 } 290 291 292 void 293 log_perror (log_error_st * const errh, 294 const char * const filename, const unsigned int line, 295 const char * const fmt, ...) 296 { 297 va_list ap; 298 va_start(ap, fmt); 299 log_error_va_list_impl(errh, filename, line, fmt, ap, 1); 300 va_end(ap); 301 } 302 303 304 void 305 log_error_multiline (log_error_st *errh, 306 const char * const restrict filename, 307 const unsigned int line, 308 const char * const restrict multiline, 309 const size_t len, 310 const char * const restrict fmt, ...) 311 { 312 if (0 == len) return; 313 314 const int errnum = errno; 315 316 if (NULL == errh) errh = log_errh; 317 buffer * const restrict b = log_buffer_prepare(errh, filename, line); 318 if (NULL == b) return; /*(errno not modified if errh->fd == -1)*/ 319 320 va_list ap; 321 va_start(ap, fmt); 322 log_buffer_vsprintf(b, fmt, ap); 323 va_end(ap); 324 325 const uint32_t prefix_len = buffer_clen(b); 326 const char * const end = multiline + len; 327 for (const char *pos = multiline; pos < end; ++pos) { 328 const char * const current_line = pos; 329 pos = strchr(pos, '\n'); 330 if (!pos) 331 pos = end; 332 size_t n = (size_t)(pos - current_line); 333 if (n && current_line[n-1] == '\r') --n; /*(skip "\r\n")*/ 334 buffer_truncate(b, prefix_len); 335 log_buffer_append_encoded(b, current_line, n); 336 log_error_write(errh, b); 337 } 338 339 buffer_clear(b); 340 errno = errnum; 341 } 342 343 344 log_error_st * 345 log_set_global_errh (log_error_st * const errh, const int ts_high_precision) 346 { 347 /* reset log_tlast 348 * -1 for cached timestamp to not match log_epoch_secs 349 * (e.g. if realtime clock init at 0) 350 * -2 for high precision timestamp */ 351 log_tlast = ts_high_precision ? -2 : -1; 352 353 buffer_free_ptr(&log_stderrh.b); 354 return (log_errh = errh ? errh : &log_stderrh); 355 } 356