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 #include <syslog.h>
  28 #include <unistd.h>
  29 #include <inttypes.h>
  30
  31 #include <cerrno>
  32 #include <cstdio>
  33 #include <cstring>
  34 #include <ctime>
  35 #include <iostream>
  36 #include <iomanip>
  37
  38 #include "shrpx_config.h"
  39 #include "shrpx_downstream.h"
  40 #include "shrpx_worker_config.h"
  41 #include "util.h"
  42 #include "template.h"
  43
  44 using namespace nghttp2;
  45
  46 namespace shrpx {
  47
  48 namespace {
  49 const char *SEVERITY_STR[] = {"INFO", "NOTICE", "WARN", "ERROR", "FATAL"};
  50 } // namespace
  51
  52 namespace {
  53 const char *SEVERITY_COLOR[] = {
  54     "\033[1;32m", // INFO
  55     "\033[1;36m", // NOTICE
  56     "\033[1;33m", // WARN
  57     "\033[1;31m", // ERROR
  58     "\033[1;35m", // FATAL
  59 };
  60 } // namespace
  61
  62 int Log::severity_thres_ = NOTICE;
  63
  64 void Log::set_severity_level(int severity) { severity_thres_ = severity; }
  65
  66 int Log::set_severity_level_by_name(const char *name) {
  67   for (size_t i = 0, max = array_size(SEVERITY_STR); i < max; ++i) {
  68     if (strcmp(SEVERITY_STR[i], name) == 0) {
  69       severity_thres_ = i;
  70       return 0;
  71     }
  72   }
  73   return -1;
  74 }
  75
  76 int severity_to_syslog_level(int severity) {
  77   switch (severity) {
  78   case (INFO):
  79     return LOG_INFO;
  80   case (NOTICE):
  81     return LOG_NOTICE;
  82   case (WARN):
  83     return LOG_WARNING;
  84   case (ERROR):
  85     return LOG_ERR;
  86   case (FATAL):
  87     return LOG_CRIT;
  88   default:
  89     return -1;
  90   }
  91 }
  92
  93 Log::Log(int severity, const char *filename, int linenum)
  94     : filename_(filename), severity_(severity), linenum_(linenum) {}
  95
  96 Log::~Log() {
  97   int rv;
  98
  99   if (!get_config()) {
 100     return;
 101   }
 102
 103   auto wconf = worker_config;
 104
 105   if (!log_enabled(severity_) ||
 106       (wconf->errorlog_fd == -1 && !get_config()->errorlog_syslog)) {
 107     return;
 108   }
 109
 110   if (get_config()->errorlog_syslog) {
 111     if (severity_ == NOTICE) {
 112       syslog(severity_to_syslog_level(severity_), "[%s] %s",
 113              SEVERITY_STR[severity_], stream_.str().c_str());
 114     } else {
 115       syslog(severity_to_syslog_level(severity_), "[%s] %s (%s:%d)",
 116              SEVERITY_STR[severity_], stream_.str().c_str(), filename_,
 117              linenum_);
 118     }
 119
 120     return;
 121   }
 122
 123   char buf[4096];
 124   auto tty = wconf->errorlog_tty;
 125
 126   wconf->update_tstamp(std::chrono::system_clock::now());
 127   auto &time_local = wconf->time_local_str;
 128
 129   if (severity_ == NOTICE) {
 130     rv = snprintf(buf, sizeof(buf), "%s PID%d [%s%s%s] %s\n",
 131                   time_local.c_str(), get_config()->pid,
 132                   tty ? SEVERITY_COLOR[severity_] : "", SEVERITY_STR[severity_],
 133                   tty ? "\033[0m" : "", stream_.str().c_str());
 134   } else {
 135     rv = snprintf(buf, sizeof(buf), "%s PID%d [%s%s%s] %s%s:%d%s %s\n",
 136                   time_local.c_str(), get_config()->pid,
 137                   tty ? SEVERITY_COLOR[severity_] : "", SEVERITY_STR[severity_],
 138                   tty ? "\033[0m" : "", tty ? "\033[1;30m" : "", filename_,
 139                   linenum_, tty ? "\033[0m" : "", stream_.str().c_str());
 140   }
 141
 142   if (rv < 0) {
 143     return;
 144   }
 145
 146   auto nwrite = std::min(static_cast<size_t>(rv), sizeof(buf) - 1);
 147
 148   while (write(wconf->errorlog_fd, buf, nwrite) == -1 && errno == EINTR)
 149     ;
 150 }
 151
 152 namespace {
 153 template <typename OutputIterator>
 154 std::pair<OutputIterator, size_t> copy(const char *src, size_t avail,
 155                                        OutputIterator oitr) {
 156   auto nwrite = std::min(strlen(src), avail);
 157   auto noitr = std::copy_n(src, nwrite, oitr);
 158   return std::make_pair(noitr, avail - nwrite);
 159 }
 160 } // namespace
 161
 162 void upstream_accesslog(const std::vector<LogFragment> &lfv, LogSpec *lgsp) {
 163   auto wconf = worker_config;
 164
 165   if (wconf->accesslog_fd == -1 && !get_config()->accesslog_syslog) {
 166     return;
 167   }
 168
 169   char buf[4096];
 170
 171   auto downstream = lgsp->downstream;
 172
 173   auto p = buf;
 174   auto avail = sizeof(buf) - 2;
 175
 176   wconf->update_tstamp(lgsp->time_now);
 177   auto &time_local = wconf->time_local_str;
 178   auto &time_iso8601 = wconf->time_iso8601_str;
 179
 180   for (auto &lf : lfv) {
 181     switch (lf.type) {
 182     case SHRPX_LOGF_LITERAL:
 183       std::tie(p, avail) = copy(lf.value.get(), avail, p);
 184       break;
 185     case SHRPX_LOGF_REMOTE_ADDR:
 186       std::tie(p, avail) = copy(lgsp->remote_addr, avail, p);
 187       break;
 188     case SHRPX_LOGF_TIME_LOCAL:
 189       std::tie(p, avail) = copy(time_local.c_str(), avail, p);
 190       break;
 191     case SHRPX_LOGF_TIME_ISO8601:
 192       std::tie(p, avail) = copy(time_iso8601.c_str(), avail, p);
 193       break;
 194     case SHRPX_LOGF_REQUEST:
 195       std::tie(p, avail) = copy(lgsp->method, avail, p);
 196       std::tie(p, avail) = copy(" ", avail, p);
 197       std::tie(p, avail) = copy(lgsp->path, avail, p);
 198       std::tie(p, avail) = copy(" HTTP/", avail, p);
 199       std::tie(p, avail) = copy(util::utos(lgsp->major).c_str(), avail, p);
 200       std::tie(p, avail) = copy(".", avail, p);
 201       std::tie(p, avail) = copy(util::utos(lgsp->minor).c_str(), avail, p);
 202       break;
 203     case SHRPX_LOGF_STATUS:
 204       std::tie(p, avail) = copy(util::utos(lgsp->status).c_str(), avail, p);
 205       break;
 206     case SHRPX_LOGF_BODY_BYTES_SENT:
 207       std::tie(p, avail) =
 208           copy(util::utos(lgsp->body_bytes_sent).c_str(), avail, p);
 209       break;
 210     case SHRPX_LOGF_HTTP:
 211       if (downstream) {
 212         auto hd = downstream->get_request_header(lf.value.get());
 213         if (hd) {
 214           std::tie(p, avail) = copy((*hd).value.c_str(), avail, p);
 215           break;
 216         }
 217       }
 218
 219       std::tie(p, avail) = copy("-", avail, p);
 220
 221       break;
 222     case SHRPX_LOGF_REMOTE_PORT:
 223       std::tie(p, avail) = copy(lgsp->remote_port, avail, p);
 224       break;
 225     case SHRPX_LOGF_SERVER_PORT:
 226       std::tie(p, avail) =
 227           copy(util::utos(lgsp->server_port).c_str(), avail, p);
 228       break;
 229     case SHRPX_LOGF_REQUEST_TIME: {
 230       auto t = std::chrono::duration_cast<std::chrono::milliseconds>(
 231                    lgsp->request_end_time - lgsp->request_start_time).count();
 232
 233       auto frac = util::utos(t % 1000);
 234       auto sec = util::utos(t / 1000);
 235       if (frac.size() < 3) {
 236         frac = std::string(3 - frac.size(), '0') + frac;
 237       }
 238       sec += ".";
 239       sec += frac;
 240
 241       std::tie(p, avail) = copy(sec.c_str(), avail, p);
 242     } break;
 243     case SHRPX_LOGF_PID:
 244       std::tie(p, avail) = copy(util::utos(lgsp->pid).c_str(), avail, p);
 245       break;
 246     case SHRPX_LOGF_ALPN:
 247       std::tie(p, avail) = copy(lgsp->alpn, avail, p);
 248       break;
 249     case SHRPX_LOGF_NONE:
 250       break;
 251     default:
 252       break;
 253     }
 254   }
 255
 256   *p = '\0';
 257
 258   if (get_config()->accesslog_syslog) {
 259     syslog(LOG_INFO, "%s", buf);
 260
 261     return;
 262   }
 263
 264   *p++ = '\n';
 265
 266   auto nwrite = p - buf;
 267   while (write(wconf->accesslog_fd, buf, nwrite) == -1 && errno == EINTR)
 268     ;
 269 }
 270
 271 int reopen_log_files() {
 272   int res = 0;
 273
 274   auto wconf = worker_config;
 275
 276   if (wconf->accesslog_fd != -1) {
 277     close(wconf->accesslog_fd);
 278     wconf->accesslog_fd = -1;
 279   }
 280
 281   if (!get_config()->accesslog_syslog && get_config()->accesslog_file) {
 282
 283     wconf->accesslog_fd =
 284         util::reopen_log_file(get_config()->accesslog_file.get());
 285
 286     if (wconf->accesslog_fd == -1) {
 287       LOG(ERROR) << "Failed to open accesslog file "
 288                  << get_config()->accesslog_file.get();
 289       res = -1;
 290     }
 291   }
 292
 293   int new_errorlog_fd = -1;
 294
 295   if (!get_config()->errorlog_syslog && get_config()->errorlog_file) {
 296
 297     new_errorlog_fd = util::reopen_log_file(get_config()->errorlog_file.get());
 298
 299     if (new_errorlog_fd == -1) {
 300       if (wconf->errorlog_fd != -1) {
 301         LOG(ERROR) << "Failed to open errorlog file "
 302                    << get_config()->errorlog_file.get();
 303       } else {
 304         std::cerr << "Failed to open errorlog file "
 305                   << get_config()->errorlog_file.get() << std::endl;
 306       }
 307
 308       res = -1;
 309     }
 310   }
 311
 312   if (wconf->errorlog_fd != -1) {
 313     close(wconf->errorlog_fd);
 314     wconf->errorlog_fd = -1;
 315     wconf->errorlog_tty = false;
 316   }
 317
 318   if (new_errorlog_fd != -1) {
 319     wconf->errorlog_fd = new_errorlog_fd;
 320     wconf->errorlog_tty = isatty(wconf->errorlog_fd);
 321   }
 322
 323   return res;
 324 }
 325
 326 } // namespace shrpx