src/shrpx_log.cc

   1 /*
   2  * nghttp2 - HTTP/2 C Library
   3  *
   4  * Copyright (c) 2012 Tatsuhiro Tsujikawa
   5  *
   6  * Permission is hereby granted, free of charge, to any person obtaining
   7  * a copy of this software and associated documentation files (the
   8  * "Software"), to deal in the Software without restriction, including
   9  * without limitation the rights to use, copy, modify, merge, publish,
  10  * distribute, sublicense, and/or sell copies of the Software, and to
  11  * permit persons to whom the Software is furnished to do so, subject to
  12  * the following conditions:
  13  *
  14  * The above copyright notice and this permission notice shall be
  15  * included in all copies or substantial portions of the Software.
  16  *
  17  * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND,
  18  * EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
  19  * MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND
  20  * NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE
  21  * LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION
  22  * OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION
  23  * WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
  24  */
  25 #include "shrpx_log.h"
  26
  27 #ifdef HAVE_SYSLOG_H
  28 #include <syslog.h>
  29 #endif // HAVE_SYSLOG_H
  30 #ifdef HAVE_UNISTD_H
  31 #include <unistd.h>
  32 #endif // HAVE_UNISTD_H
  33 #ifdef HAVE_INTTYPES_H
  34 #include <inttypes.h>
  35 #endif // HAVE_INTTYPES_H
  36
  37 #include <cerrno>
  38 #include <cstdio>
  39 #include <cstring>
  40 #include <ctime>
  41 #include <iostream>
  42 #include <iomanip>
  43
  44 #include "shrpx_config.h"
  45 #include "shrpx_downstream.h"
  46 #include "util.h"
  47 #include "template.h"
  48
  49 using namespace nghttp2;
  50
  51 namespace shrpx {
  52
  53 namespace {
  54 const char *SEVERITY_STR[] = {"INFO", "NOTICE", "WARN", "ERROR", "FATAL"};
  55 } // namespace
  56
  57 namespace {
  58 const char *SEVERITY_COLOR[] = {
  59     "\033[1;32m", // INFO
  60     "\033[1;36m", // NOTICE
  61     "\033[1;33m", // WARN
  62     "\033[1;31m", // ERROR
  63     "\033[1;35m", // FATAL
  64 };
  65 } // namespace
  66
  67 int Log::severity_thres_ = NOTICE;
  68
  69 void Log::set_severity_level(int severity) { severity_thres_ = severity; }
  70
  71 int Log::set_severity_level_by_name(const char *name) {
  72   for (size_t i = 0, max = array_size(SEVERITY_STR); i < max; ++i) {
  73     if (strcmp(SEVERITY_STR[i], name) == 0) {
  74       severity_thres_ = i;
  75       return 0;
  76     }
  77   }
  78   return -1;
  79 }
  80
  81 int severity_to_syslog_level(int severity) {
  82   switch (severity) {
  83   case (INFO):
  84     return LOG_INFO;
  85   case (NOTICE):
  86     return LOG_NOTICE;
  87   case (WARN):
  88     return LOG_WARNING;
  89   case (ERROR):
  90     return LOG_ERR;
  91   case (FATAL):
  92     return LOG_CRIT;
  93   default:
  94     return -1;
  95   }
  96 }
  97
  98 Log::Log(int severity, const char *filename, int linenum)
  99     : filename_(filename), severity_(severity), linenum_(linenum) {}
 100
 101 Log::~Log() {
 102   int rv;
 103
 104   if (!get_config()) {
 105     return;
 106   }
 107
 108   auto lgconf = log_config();
 109
 110   if (!log_enabled(severity_) ||
 111       (lgconf->errorlog_fd == -1 && !get_config()->errorlog_syslog)) {
 112     return;
 113   }
 114
 115   if (get_config()->errorlog_syslog) {
 116     if (severity_ == NOTICE) {
 117       syslog(severity_to_syslog_level(severity_), "[%s] %s",
 118              SEVERITY_STR[severity_], stream_.str().c_str());
 119     } else {
 120       syslog(severity_to_syslog_level(severity_), "[%s] %s (%s:%d)",
 121              SEVERITY_STR[severity_], stream_.str().c_str(), filename_,
 122              linenum_);
 123     }
 124
 125     return;
 126   }
 127
 128   char buf[4096];
 129   auto tty = lgconf->errorlog_tty;
 130
 131   lgconf->update_tstamp(std::chrono::system_clock::now());
 132   auto &time_local = lgconf->time_local_str;
 133
 134   if (severity_ == NOTICE) {
 135     rv = snprintf(buf, sizeof(buf), "%s PID%d [%s%s%s] %s\n",
 136                   time_local.c_str(), get_config()->pid,
 137                   tty ? SEVERITY_COLOR[severity_] : "", SEVERITY_STR[severity_],
 138                   tty ? "\033[0m" : "", stream_.str().c_str());
 139   } else {
 140     rv = snprintf(buf, sizeof(buf), "%s PID%d [%s%s%s] %s%s:%d%s %s\n",
 141                   time_local.c_str(), get_config()->pid,
 142                   tty ? SEVERITY_COLOR[severity_] : "", SEVERITY_STR[severity_],
 143                   tty ? "\033[0m" : "", tty ? "\033[1;30m" : "", filename_,
 144                   linenum_, tty ? "\033[0m" : "", stream_.str().c_str());
 145   }
 146
 147   if (rv < 0) {
 148     return;
 149   }
 150
 151   auto nwrite = std::min(static_cast<size_t>(rv), sizeof(buf) - 1);
 152
 153   while (write(lgconf->errorlog_fd, buf, nwrite) == -1 && errno == EINTR)
 154     ;
 155 }
 156
 157 namespace {
 158 template <typename OutputIterator>
 159 std::pair<OutputIterator, size_t> copy(const char *src, size_t avail,
 160                                        OutputIterator oitr) {
 161   auto nwrite = std::min(strlen(src), avail);
 162   auto noitr = std::copy_n(src, nwrite, oitr);
 163   return std::make_pair(noitr, avail - nwrite);
 164 }
 165 } // namespace
 166
 167 void upstream_accesslog(const std::vector<LogFragment> &lfv,
 168                         const LogSpec &lgsp) {
 169   auto lgconf = log_config();
 170
 171   if (lgconf->accesslog_fd == -1 && !get_config()->accesslog_syslog) {
 172     return;
 173   }
 174
 175   char buf[4096];
 176
 177   auto downstream = lgsp.downstream;
 178
 179   auto p = buf;
 180   auto avail = sizeof(buf) - 2;
 181
 182   lgconf->update_tstamp(lgsp.time_now);
 183   auto &time_local = lgconf->time_local_str;
 184   auto &time_iso8601 = lgconf->time_iso8601_str;
 185
 186   for (auto &lf : lfv) {
 187     switch (lf.type) {
 188     case SHRPX_LOGF_LITERAL:
 189       std::tie(p, avail) = copy(lf.value.get(), avail, p);
 190       break;
 191     case SHRPX_LOGF_REMOTE_ADDR:
 192       std::tie(p, avail) = copy(lgsp.remote_addr, avail, p);
 193       break;
 194     case SHRPX_LOGF_TIME_LOCAL:
 195       std::tie(p, avail) = copy(time_local.c_str(), avail, p);
 196       break;
 197     case SHRPX_LOGF_TIME_ISO8601:
 198       std::tie(p, avail) = copy(time_iso8601.c_str(), avail, p);
 199       break;
 200     case SHRPX_LOGF_REQUEST:
 201       std::tie(p, avail) = copy(lgsp.method, avail, p);
 202       std::tie(p, avail) = copy(" ", avail, p);
 203       std::tie(p, avail) = copy(lgsp.path, avail, p);
 204       std::tie(p, avail) = copy(" HTTP/", avail, p);
 205       std::tie(p, avail) = copy(util::utos(lgsp.major).c_str(), avail, p);
 206       if (lgsp.major < 2) {
 207         std::tie(p, avail) = copy(".", avail, p);
 208         std::tie(p, avail) = copy(util::utos(lgsp.minor).c_str(), avail, p);
 209       }
 210       break;
 211     case SHRPX_LOGF_STATUS:
 212       std::tie(p, avail) = copy(util::utos(lgsp.status).c_str(), avail, p);
 213       break;
 214     case SHRPX_LOGF_BODY_BYTES_SENT:
 215       std::tie(p, avail) =
 216           copy(util::utos(lgsp.body_bytes_sent).c_str(), avail, p);
 217       break;
 218     case SHRPX_LOGF_HTTP:
 219       if (downstream) {
 220         auto hd = downstream->get_request_header(lf.value.get());
 221         if (hd) {
 222           std::tie(p, avail) = copy((*hd).value.c_str(), avail, p);
 223           break;
 224         }
 225       }
 226
 227       std::tie(p, avail) = copy("-", avail, p);
 228
 229       break;
 230     case SHRPX_LOGF_REMOTE_PORT:
 231       std::tie(p, avail) = copy(lgsp.remote_port, avail, p);
 232       break;
 233     case SHRPX_LOGF_SERVER_PORT:
 234       std::tie(p, avail) = copy(util::utos(lgsp.server_port).c_str(), avail, p);
 235       break;
 236     case SHRPX_LOGF_REQUEST_TIME: {
 237       auto t = std::chrono::duration_cast<std::chrono::milliseconds>(
 238                    lgsp.request_end_time - lgsp.request_start_time).count();
 239
 240       auto frac = util::utos(t % 1000);
 241       auto sec = util::utos(t / 1000);
 242       if (frac.size() < 3) {
 243         frac = std::string(3 - frac.size(), '0') + frac;
 244       }
 245       sec += ".";
 246       sec += frac;
 247
 248       std::tie(p, avail) = copy(sec.c_str(), avail, p);
 249     } break;
 250     case SHRPX_LOGF_PID:
 251       std::tie(p, avail) = copy(util::utos(lgsp.pid).c_str(), avail, p);
 252       break;
 253     case SHRPX_LOGF_ALPN:
 254       std::tie(p, avail) = copy(lgsp.alpn, avail, p);
 255       break;
 256     case SHRPX_LOGF_NONE:
 257       break;
 258     default:
 259       break;
 260     }
 261   }
 262
 263   *p = '\0';
 264
 265   if (get_config()->accesslog_syslog) {
 266     syslog(LOG_INFO, "%s", buf);
 267
 268     return;
 269   }
 270
 271   *p++ = '\n';
 272
 273   auto nwrite = p - buf;
 274   while (write(lgconf->accesslog_fd, buf, nwrite) == -1 && errno == EINTR)
 275     ;
 276 }
 277
 278 int reopen_log_files() {
 279   int res = 0;
 280
 281   auto lgconf = log_config();
 282
 283   if (lgconf->accesslog_fd != -1) {
 284     close(lgconf->accesslog_fd);
 285     lgconf->accesslog_fd = -1;
 286   }
 287
 288   if (!get_config()->accesslog_syslog && get_config()->accesslog_file) {
 289
 290     lgconf->accesslog_fd =
 291         util::reopen_log_file(get_config()->accesslog_file.get());
 292
 293     if (lgconf->accesslog_fd == -1) {
 294       LOG(ERROR) << "Failed to open accesslog file "
 295                  << get_config()->accesslog_file.get();
 296       res = -1;
 297     }
 298   }
 299
 300   int new_errorlog_fd = -1;
 301
 302   if (!get_config()->errorlog_syslog && get_config()->errorlog_file) {
 303
 304     new_errorlog_fd = util::reopen_log_file(get_config()->errorlog_file.get());
 305
 306     if (new_errorlog_fd == -1) {
 307       if (lgconf->errorlog_fd != -1) {
 308         LOG(ERROR) << "Failed to open errorlog file "
 309                    << get_config()->errorlog_file.get();
 310       } else {
 311         std::cerr << "Failed to open errorlog file "
 312                   << get_config()->errorlog_file.get() << std::endl;
 313       }
 314
 315       res = -1;
 316     }
 317   }
 318
 319   if (lgconf->errorlog_fd != -1) {
 320     close(lgconf->errorlog_fd);
 321     lgconf->errorlog_fd = -1;
 322     lgconf->errorlog_tty = false;
 323   }
 324
 325   if (new_errorlog_fd != -1) {
 326     lgconf->errorlog_fd = new_errorlog_fd;
 327     lgconf->errorlog_tty = isatty(lgconf->errorlog_fd);
 328   }
 329
 330   return res;
 331 }
 332
 333 void redirect_stderr_to_errorlog() {
 334   auto lgconf = log_config();
 335
 336   if (get_config()->errorlog_syslog || lgconf->errorlog_fd == -1) {
 337     return;
 338   }
 339
 340   dup2(lgconf->errorlog_fd, STDERR_FILENO);
 341 }
 342
 343 } // namespace shrpx