walkero
/
nghttp2
1
0
Fork 0
Code Issues Pull Requests Projects Releases 1 Wiki Activity

Merge branch 'nghttpx-accesslog-timestamp'

This commit is contained in:
Tatsuhiro Tsujikawa 2017-01-11 21:14:12 +09:00
parent 9067ff5eee 33aa327ef5
commit 4e9098bccf
11 changed files with 65 additions and 69 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

33
src/shrpx_client_handler.cc
View File

@ -1230,12 +1230,18 @@ StringRef construct_absolute_request_uri(BlockAllocator &balloc,
void ClientHandler::write_accesslog(Downstream *downstream) {
nghttp2::ssl::TLSSessionInfo tls_info;
const auto &req = downstream->request();
auto &req = downstream->request();
const auto &resp = downstream->response();
auto &balloc = downstream->get_block_allocator();
auto config = get_config();
if (!req.tstamp) {
auto lgconf = log_config();
lgconf->update_tstamp(std::chrono::system_clock::now());
req.tstamp = lgconf->tstamp;
}
upstream_accesslog(
config->logging.access.format,
LogSpec{
@ -1253,8 +1259,6 @@ void ClientHandler::write_accesslog(Downstream *downstream) {
: StringRef(req.path),
alpn_, nghttp2::ssl::get_tls_session_info(&tls_info, conn_.tls.ssl),
std::chrono::system_clock::now(), // time_now
downstream->get_request_start_time(), // request_start_time
std::chrono::high_resolution_clock::now(), // request_end_time
@ -1264,29 +1268,6 @@ void ClientHandler::write_accesslog(Downstream *downstream) {
});
}
void ClientHandler::write_accesslog(int major, int minor, unsigned int status,
int64_t body_bytes_sent) {
auto time_now = std::chrono::system_clock::now();
auto highres_now = std::chrono::high_resolution_clock::now();
nghttp2::ssl::TLSSessionInfo tls_info;
auto config = get_config();
upstream_accesslog(
config->logging.access.format,
LogSpec{
nullptr, nullptr, ipaddr_,
StringRef::from_lit("-"), // method
StringRef::from_lit("-"), // path,
alpn_, nghttp2::ssl::get_tls_session_info(&tls_info, conn_.tls.ssl),
time_now,
highres_now, // request_start_time TODO is
// there a better value?
highres_now, // request_end_time
major, minor, // major, minor
status, body_bytes_sent, port_, faddr_->port, config->pid,
});
}
ClientHandler::ReadBuf *ClientHandler::get_rb() { return &rb_; }
void ClientHandler::signal_write() { conn_.wlimit.startw(); }

4
src/shrpx_client_handler.h
View File

@ -118,10 +118,6 @@ public:
// must not be nullptr.
void write_accesslog(Downstream *downstream);
// Writes upstream accesslog. This function is used if
// corresponding Downstream object is not available.
void write_accesslog(int major, int minor, unsigned int status,
int64_t body_bytes_sent);
Worker *get_worker() const;
using ReadBuf = DefaultMemchunkBuffer;

2
src/shrpx_downstream.h
View File

@ -152,6 +152,8 @@ struct Request {
}
FieldStore fs;
// Timestamp when all request header fields are received.
std::shared_ptr<Timestamp> tstamp;
// Request scheme. For HTTP/2, this is :scheme header field value.
// For HTTP/1.1, this is deduced from URI or connection.
StringRef scheme;

8
src/shrpx_http2_upstream.cc
View File

@ -296,11 +296,15 @@ int on_begin_headers_callback(nghttp2_session *session,
int Http2Upstream::on_request_headers(Downstream *downstream,
const nghttp2_frame *frame) {
auto lgconf = log_config();
lgconf->update_tstamp(std::chrono::system_clock::now());
auto &req = downstream->request();
req.tstamp = lgconf->tstamp;
if (downstream->get_response_state() == Downstream::MSG_COMPLETE) {
return 0;
}
auto &req = downstream->request();
auto &nva = req.fs.headers();
if (LOG_ENABLED(INFO)) {
@ -1489,7 +1493,7 @@ int Http2Upstream::error_reply(Downstream *downstream,
auto response_status = http2::stringify_status(balloc, status_code);
auto content_length = util::make_string_ref_uint(balloc, html.size());
auto date = make_string_ref(balloc, lgconf->time_http);
auto date = make_string_ref(balloc, lgconf->tstamp->time_http);
auto nva = std::array<nghttp2_nv, 5>{
{http2::make_nv_ls_nocopy(":status", response_status),

6
src/shrpx_https_upstream.cc
View File

@ -292,6 +292,10 @@ int htp_hdrs_completecb(http_parser *htp) {
auto downstream = upstream->get_downstream();
auto &req = downstream->request();
auto lgconf = log_config();
lgconf->update_tstamp(std::chrono::system_clock::now());
req.tstamp = lgconf->tstamp;
req.http_major = htp->http_major;
req.http_minor = htp->http_minor;
@ -950,7 +954,7 @@ void HttpsUpstream::error_reply(unsigned int status_code) {
output->append("\r\nDate: ");
auto lgconf = log_config();
lgconf->update_tstamp(std::chrono::system_clock::now());
output->append(lgconf->time_http);
output->append(lgconf->tstamp->time_http);
output->append("\r\nContent-Type: text/html; "
"charset=UTF-8\r\nConnection: close\r\n\r\n");
output->append(html);

37
src/shrpx_log.cc
View File

@ -146,7 +146,7 @@ Log::~Log() {
// Error log format: <datetime> <master-pid> <current-pid>
// <thread-id> <level> (<filename>:<line>) <msg>
rv = snprintf(buf, sizeof(buf), "%s %d %d %s %s%s%s (%s:%d) %s\n",
lgconf->time_iso8601.c_str(), config->pid, lgconf->pid,
lgconf->tstamp->time_iso8601.c_str(), config->pid, lgconf->pid,
lgconf->thread_id.c_str(), tty ? SEVERITY_COLOR[severity_] : "",
SEVERITY_STR[severity_].c_str(), tty ? "\033[0m" : "",
filename_, linenum_, stream_.str().c_str());
@ -242,18 +242,12 @@ void upstream_accesslog(const std::vector<LogFragment> &lfv,
auto downstream = lgsp.downstream;
const Request *req = nullptr;
if (downstream) {
req = &downstream->request();
}
const auto &req = downstream->request();
const auto &tstamp = req.tstamp;
auto p = buf;
auto avail = sizeof(buf) - 2;
lgconf->update_tstamp(lgsp.time_now);
auto &time_local = lgconf->time_local;
auto &time_iso8601 = lgconf->time_iso8601;
for (auto &lf : lfv) {
switch (lf.type) {
case SHRPX_LOGF_LITERAL:
@ -263,10 +257,10 @@ void upstream_accesslog(const std::vector<LogFragment> &lfv,
std::tie(p, avail) = copy(lgsp.remote_addr, avail, p);
break;
case SHRPX_LOGF_TIME_LOCAL:
std::tie(p, avail) = copy(time_local, avail, p);
std::tie(p, avail) = copy(tstamp->time_local, avail, p);
break;
case SHRPX_LOGF_TIME_ISO8601:
std::tie(p, avail) = copy(time_iso8601, avail, p);
std::tie(p, avail) = copy(tstamp->time_iso8601, avail, p);
break;
case SHRPX_LOGF_REQUEST:
std::tie(p, avail) = copy(lgsp.method, avail, p);
@ -285,24 +279,21 @@ void upstream_accesslog(const std::vector<LogFragment> &lfv,
case SHRPX_LOGF_BODY_BYTES_SENT:
std::tie(p, avail) = copy(util::utos(lgsp.body_bytes_sent), avail, p);
break;
case SHRPX_LOGF_HTTP:
if (req) {
auto hd = req->fs.header(lf.value);
if (hd) {
std::tie(p, avail) = copy((*hd).value, avail, p);
break;
}
case SHRPX_LOGF_HTTP: {
auto hd = req.fs.header(lf.value);
if (hd) {
std::tie(p, avail) = copy((*hd).value, avail, p);
break;
}
std::tie(p, avail) = copy_l("-", avail, p);
break;
}
case SHRPX_LOGF_AUTHORITY:
if (req) {
if (!req->authority.empty()) {
std::tie(p, avail) = copy(req->authority, avail, p);
break;
}
if (!req.authority.empty()) {
std::tie(p, avail) = copy(req.authority, avail, p);
break;
}
std::tie(p, avail) = copy_l("-", avail, p);

1
src/shrpx_log.h
View File

@ -151,7 +151,6 @@ struct LogSpec {
StringRef path;
StringRef alpn;
const nghttp2::ssl::TLSSessionInfo *tls_info;
std::chrono::system_clock::time_point time_now;
std::chrono::high_resolution_clock::time_point request_start_time;
std::chrono::high_resolution_clock::time_point request_end_time;
int major, minor;

21
src/shrpx_log_config.cc
View File

@ -35,8 +35,19 @@ using namespace nghttp2;
namespace shrpx {
Timestamp::Timestamp(const std::chrono::system_clock::time_point &tp) {
time_local = util::format_common_log(time_local_buf.data(), tp);
time_iso8601 = util::format_iso8601(time_iso8601_buf.data(), tp);
time_http = util::format_http_date(time_http_buf.data(), tp);
}
LogConfig::LogConfig()
: pid(getpid()), accesslog_fd(-1), errorlog_fd(-1), errorlog_tty(false) {
: time_str_updated(std::chrono::system_clock::now()),
tstamp(std::make_shared<Timestamp>(time_str_updated)),
pid(getpid()),
accesslog_fd(-1),
errorlog_fd(-1),
errorlog_tty(false) {
auto tid = std::this_thread::get_id();
auto tid_hash =
util::hash32(StringRef{reinterpret_cast<uint8_t *>(&tid),
@ -87,17 +98,15 @@ void delete_log_config() {}
void LogConfig::update_tstamp(
const std::chrono::system_clock::time_point &now) {
auto t0 = std::chrono::system_clock::to_time_t(time_str_updated_);
auto t0 = std::chrono::system_clock::to_time_t(time_str_updated);
auto t1 = std::chrono::system_clock::to_time_t(now);
if (t0 == t1) {
return;
}
time_str_updated_ = now;
time_str_updated = now;
time_local = util::format_common_log(time_local_buf.data(), now);
time_iso8601 = util::format_iso8601(time_iso8601_buf.data(), now);
time_http = util::format_http_date(time_http_buf.data(), now);
tstamp = std::make_shared<Timestamp>(now);
}
} // namespace shrpx

12
src/shrpx_log_config.h
View File

@ -37,15 +37,21 @@ using namespace nghttp2;
namespace shrpx {
struct LogConfig {
std::chrono::system_clock::time_point time_str_updated_;
struct Timestamp {
Timestamp(const std::chrono::system_clock::time_point &tp);
std::array<char, sizeof("03/Jul/2014:00:19:38 +0900")> time_local_buf;
std::array<char, sizeof("2014-11-15T12:58:24.741+09:00")> time_iso8601_buf;
std::array<char, sizeof("Mon, 10 Oct 2016 10:25:58 GMT")> time_http_buf;
std::string thread_id;
StringRef time_local;
StringRef time_iso8601;
StringRef time_http;
};
struct LogConfig {
std::chrono::system_clock::time_point time_str_updated;
std::shared_ptr<Timestamp> tstamp;
std::string thread_id;
pid_t pid;
int accesslog_fd;
int errorlog_fd;

4
src/shrpx_mruby_module_response.cc
View File

@ -255,8 +255,8 @@ mrb_value response_return(mrb_state *mrb, mrb_value self) {
auto lgconf = log_config();
lgconf->update_tstamp(std::chrono::system_clock::now());
resp.fs.add_header_token(StringRef::from_lit("date"),
make_string_ref(balloc, lgconf->time_http), false,
http2::HD_DATE);
make_string_ref(balloc, lgconf->tstamp->time_http),
false, http2::HD_DATE);
}
auto upstream = downstream->get_upstream();

6
src/shrpx_spdy_upstream.cc
View File

@ -181,6 +181,10 @@ void on_ctrl_recv_callback(spdylay_session *session, spdylay_frame_type type,
auto &balloc = downstream->get_block_allocator();
auto lgconf = log_config();
lgconf->update_tstamp(std::chrono::system_clock::now());
req.tstamp = lgconf->tstamp;
downstream->reset_upstream_rtimer();
auto nv = frame->syn_stream.nv;
@ -1006,7 +1010,7 @@ int SpdyUpstream::error_reply(Downstream *downstream,
"content-type", "text/html; charset=UTF-8",
"server", get_config()->http.server_name.c_str(),
"content-length", content_length.c_str(),
"date", lgconf->time_http.c_str(),
"date", lgconf->tstamp->time_http.c_str(),
nullptr};
rv = spdylay_submit_response(session_, downstream->get_stream_id(), nv,