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