Commit 99ca98cf authored by Ciarán Ó Rourke's avatar Ciarán Ó Rourke
Browse files

Implement logging

Use the spdlog library for project wide logging to a file. Path of
logfile is configurable as command line option.

Change log:
* use spdlog
* set global logging to file
* logfile as command line option
* update README command line option section with logfile option
* update README command line option section with default values for options
* control log level with CMake build type variable
* log received request
* get request logging
* put request logging
* getmd request logging
* fifo logging
* rename authorisation macro to comply with linter
* use rotating files with size limit
parent d7d4c49c
Pipeline #1811 passed with stages
in 8 minutes and 7 seconds
......@@ -48,6 +48,7 @@ image: ciaranorourke/fiphoboserver:debian
- apt-get install -y
cmake
clang clang-tidy
libspdlog-dev
script:
- *start_phobos
- *configure
......
......@@ -92,10 +92,11 @@ The `start` subcommand supports a number of optional flags and options.
#### Flags/Options
Flag/Option | Effect
----------- | ------
`--http INT` | Set the port to listen on with HTTP protocol.
`--http2 INT` | Set the port to listen on with HTTP2 protocol.
`-t,--threads INT` | Set the number of threads to listen on (<= 0 will use number of available cores).
`-w,--write-config TEXT` | Write the configuration to `TEXT`
`--http INT` | Set the port to listen on with HTTP protocol (Default `11000`).
`--http2 INT` | Set the port to listen on with HTTP2 protocol (Default `11002`).
`-t,--threads INT` | Set the number of threads to listen on, <= 0 will use number of available cores (Default `0`).
`-w,--write-config TEXT` | Write the configuration to `TEXT`.
`-l,--logfile` | Set the filename to write logs to (Default `/tmp/fiphoboserver_log.txt").
Options can also be given to the `start` subcommand using `--config [config_filename]`. Note that if `hostname` is specified in the configuration file then the `--config` options must be suppied before the `start` subcommand;
```
......@@ -115,4 +116,4 @@ One possible way most SDKs use automatically is the file `~/.aws/credentials`. T
[default]
aws_access_key_id = OPEN_KEY
aws_secret_access_key = SECRET_KEY
```
\ No newline at end of file
```
/*
* Copyright (c) Facebook, Inc. and its affiliates.
* All rights reserved.
*
* This source code is licensed under the BSD-style license found in the
* LICENSE file in the root directory of this source tree.
*/
#include <folly/executors/CPUThreadPoolExecutor.h>
#include <folly/executors/GlobalExecutor.h>
#include <folly/init/Init.h>
......@@ -17,10 +9,14 @@
#include <sys/types.h>
#include <unistd.h>
#include <spdlog/sinks/rotating_file_sink.h>
#include <spdlog/spdlog.h>
#include "fiphoboserver_exception.h"
#include "server/handler_factory.h"
#include "utils/config.h"
using folly::SocketAddress;
using Protocol = proxygen::HTTPServer::Protocol;
......@@ -106,6 +102,15 @@ int main(int argc, char* argv[])
return EXIT_SUCCESS;
}
auto max_logfile_size = 1048576 * 5;
auto max_logfiles = 3;
spdlog::set_default_logger(spdlog::rotating_logger_mt(
"fiphoboserver", parse_result.log_filename, max_logfile_size,
max_logfiles));
#ifndef NDEBUG
spdlog::set_level(spdlog::level::debug);
#endif
proxygen::HTTPServerOptions options;
options.threads = static_cast<size_t>(parse_result.thread_count);
options.idleTimeout = std::chrono::milliseconds(60000);
......@@ -125,7 +130,7 @@ int main(int argc, char* argv[])
server.bind(IPs);
/* Start HTTPServer mainloop in a separate thread */
std::cout << "Starting server" << std::endl;
spdlog::info("Starting server");
std::thread t([&]() { server.start(); });
t.join();
......
......@@ -11,7 +11,7 @@ add_library(
if(FIPHOBOSERVER_DISABLE_AUTHORISATION)
message("Disabling AWS V4 authorisation for the server")
set_target_properties(server PROPERTIES COMPILE_DEFINITIONS "NO_AUTHORISATION")
set_target_properties(server PROPERTIES COMPILE_DEFINITIONS "FIPHOBOSERVER_NO_AUTHORISATION")
endif(FIPHOBOSERVER_DISABLE_AUTHORISATION)
#SET(CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -fsanitize=address -O1")
......
......@@ -15,25 +15,23 @@
#include <folly/io/async/EventBaseManager.h>
#include <proxygen/httpserver/ResponseBuilder.h>
#include <spdlog/spdlog.h>
namespace fiphoboserver {
void GetRequestHandler::onRequest(
std::unique_ptr<proxygen::HTTPMessage> headers) noexcept
{
if (headers->getMethod() != proxygen::HTTPMethod::GET) {
proxygen::ResponseBuilder(downstream_)
.status(400, "Bad method")
.body("Only GET is supported")
.sendWithEOM();
return;
}
/* Creating Bucket queries */
m_s3_header.set_headers(std::move(headers));
// m_s3_header.print_all_headers();
#ifndef NO_AUTHORISATION
spdlog::info("bucket: {}", m_s3_header.get_bucket());
spdlog::info("key: {}", m_s3_header.get_key_without_bucket());
// spdlog::debug("body length: {}", m_s3_header.get_body_length());
spdlog::debug("queries: {}", m_s3_header.get_queries());
#ifndef FIPHOBOSERVER_NO_AUTHORISATION
s3_utilities::S3_authorisation auth;
if (auth.authorise(m_s3_header)
!= s3_utilities::Authorisation_status::valid) {
......@@ -44,6 +42,10 @@ void GetRequestHandler::onRequest(
auth_error.https_error_code, auth_error.https_error_identifier)
.body(auth_error.get_xml(m_s3_header.get_key()))
.sendWithEOM();
spdlog::warn(
"authorisation is invalid: {} ({})",
auth_error.https_error_identifier, auth_error.https_error_code);
return;
}
#endif
......@@ -51,33 +53,31 @@ void GetRequestHandler::onRequest(
std::map<std::string, std::string> meta_data;
std::string content_length;
spdlog::debug("checking if metadata exists");
try {
/* Send meta data to backend through the stream */
// m_stream->set_storage_meta_data(
// m_s3_header.get_meta_data(), m_s3_header.get_bucket());
// Check if metadata for file exists
/* Check if metadata for file exists */
meta_data = m_stream->get_meta_data(m_s3_header.get_key());
content_length = meta_data["fiphobo:content_length"];
/* Tell stream to coordinate with backend to prepare for GET operation
/*
* Tell stream to coordinate with backend to prepare for GET operation
*/
m_stream->start_get(m_s3_header.get_key());
m_stream_completed = false; // TODO: Better way of communicating this
}
catch (const std::system_error& ex) {
spdlog::warn("could not find {}", m_s3_header.get_key());
proxygen::ResponseBuilder(downstream_)
.status(404, "Not Found")
.body(folly::to<std::string>(
"Could not find ", headers->getPathAsStringPiece(),
"Could not find ", m_s3_header.get_key(),
" ex=", folly::exceptionStr(ex)))
.sendWithEOM();
return;
}
catch (const FIPhoboServerException& ex) {
std::cerr << "Caught exception: " << ex.what() << '\n';
spdlog::error("caught exception: {}", ex.what());
s3_utilities::s3_error_info error =
s3_utilities::create_s3_error(ex.get_inner_error());
......@@ -89,6 +89,10 @@ void GetRequestHandler::onRequest(
return;
}
spdlog::info("sending meta data");
spdlog::debug("meta data:");
spdlog::debug("content length: {}", content_length);
proxygen::ResponseBuilder response(downstream_);
response.status(200, "OK");
response.header("Content-Length", content_length);
......@@ -98,8 +102,10 @@ void GetRequestHandler::onRequest(
if (pair.first.rfind("fiphobo:", 0) != 0) {
response.header("x-amz-meta-" + pair.first, pair.second);
}
spdlog::debug("{}: {}", pair.first, pair.second);
});
response.send();
spdlog::info("meta data send complete");
/* Initiating a read from the stream and creating a body to send */
m_read_file_scheduled = true;
......@@ -110,6 +116,7 @@ void GetRequestHandler::onRequest(
void GetRequestHandler::read_file(folly::EventBase* evb)
{
spdlog::info("sending message body");
folly::IOBufQueue buf;
while (!m_stream_completed && !m_paused) {
/* read 4k-ish chunks and foward each one to the client */
......@@ -124,11 +131,14 @@ void GetRequestHandler::read_file(folly::EventBase* evb)
try {
auto rc = m_stream->get(data.first, data.second);
if (rc < 0) {
// should not happen as an exception should have been thrown
// before
/*
* should not happen as an exception should have been thrown
* before
*/
throw FIPhoboServerException("m_stream->get returned an error");
}
else if (rc == 0) {
spdlog::info("message body send complete");
// done
m_stream_completed = true;
m_stream->finish_io();
......@@ -139,6 +149,7 @@ void GetRequestHandler::read_file(folly::EventBase* evb)
break;
}
else {
spdlog::debug("sending {} bytes", rc);
buf.postallocate(rc);
evb->runInEventBaseThread([this, body = buf.move()]() mutable {
proxygen::ResponseBuilder(downstream_)
......@@ -148,7 +159,7 @@ void GetRequestHandler::read_file(folly::EventBase* evb)
}
}
catch (const FIPhoboServerException& ex) {
std::cerr << "Read error=" << ex.what() << '\n';
spdlog::error("read error: {}", ex.what());
s3_utilities::s3_error_info error =
s3_utilities::create_s3_error(ex.get_inner_error());
evb->runInEventBaseThread([this, error] {
......
......@@ -13,25 +13,23 @@
#include <proxygen/httpserver/ResponseBuilder.h>
#include <spdlog/spdlog.h>
namespace fiphoboserver {
void GetmdRequestHandler::onRequest(
std::unique_ptr<proxygen::HTTPMessage> headers) noexcept
{
if (headers->getMethod() != proxygen::HTTPMethod::HEAD) {
proxygen::ResponseBuilder(downstream_)
.status(400, "Bad method")
.body("Only HEAD is supported")
.sendWithEOM();
return;
}
/* Creating Bucket queries */
m_s3_header.set_headers(std::move(headers));
// m_s3_header.print_all_headers();
#ifndef NO_AUTHORISATION
spdlog::info("bucket: {}", m_s3_header.get_bucket());
spdlog::info("key: {}", m_s3_header.get_key_without_bucket());
// spdlog::debug("body length: {}", m_s3_header.get_body_length());
spdlog::debug("queries: {}", m_s3_header.get_queries());
#ifndef FIPHOBOSERVER_NO_AUTHORISATION
s3_utilities::S3_authorisation auth;
if (auth.authorise(m_s3_header)
!= s3_utilities::Authorisation_status::valid) {
......@@ -42,16 +40,21 @@ void GetmdRequestHandler::onRequest(
auth_error.https_error_code, auth_error.https_error_identifier)
.body(auth_error.get_xml(m_s3_header.get_key()))
.sendWithEOM();
spdlog::warn(
"authorisation is invalid: {} ({})",
auth_error.https_error_identifier, auth_error.https_error_code);
return;
}
#endif
spdlog::debug("checking if metadata exists");
try {
/* Get meta data from backend through the stream */
m_meta_data = m_stream->get_meta_data(m_s3_header.get_key());
}
catch (const std::system_error& ex) {
spdlog::warn("could not find {}", headers->getPathAsStringPiece());
proxygen::ResponseBuilder(downstream_)
.status(404, "Not Found")
.body(folly::to<std::string>(
......@@ -61,7 +64,7 @@ void GetmdRequestHandler::onRequest(
return;
}
catch (const FIPhoboServerException& ex) {
std::cerr << "Caught exception: " << ex.what() << '\n';
spdlog::error("caught exception: {}", ex.what());
s3_utilities::s3_error_info error =
s3_utilities::create_s3_error(ex.get_inner_error());
......@@ -72,6 +75,9 @@ void GetmdRequestHandler::onRequest(
return;
}
spdlog::info("sending meta data");
spdlog::debug("meta data:");
proxygen::ResponseBuilder response(downstream_);
response.status(200, "OK");
std::for_each(
......@@ -80,14 +86,16 @@ void GetmdRequestHandler::onRequest(
if (pair.first.rfind("fiphobo:", 0) != 0) {
response.header("x-amz-meta-" + pair.first, pair.second);
}
spdlog::debug("{}: {}", pair.first, pair.second);
});
response.sendWithEOM();
spdlog::info("meta data send complete");
}
void GetmdRequestHandler::onBody(
std::unique_ptr<folly::IOBuf> /*body*/) noexcept
{
// ignore, only support HEAD
/* ignore, only support HEAD */
}
void GetmdRequestHandler::onEOM() noexcept {}
......@@ -95,7 +103,7 @@ void GetmdRequestHandler::onEOM() noexcept {}
void GetmdRequestHandler::onUpgrade(
proxygen::UpgradeProtocol /*protocol*/) noexcept
{
// handler doesn't support upgrades
/* handler doesn't support upgrades */
}
void GetmdRequestHandler::requestComplete() noexcept
......
......@@ -48,6 +48,7 @@ class HandlerFactory : public proxygen::RequestHandlerFactory {
proxygen::RequestHandler*,
proxygen::HTTPMessage* headers) noexcept override
{
spdlog::info("{} request received", headers->getMethodString());
if (headers->getMethod() == proxygen::HTTPMethod::GET) {
return new GetRequestHandler(std::make_unique<stream::Fifo>(
std::make_unique<storage::Phobos_file>()));
......@@ -61,6 +62,8 @@ class HandlerFactory : public proxygen::RequestHandlerFactory {
std::make_unique<storage::Phobos_file>()));
}
else {
spdlog::warn(
"{} request is not supported", headers->getMethodString());
return new UnsupportedRequestHandler();
}
}
......
......@@ -11,15 +11,18 @@
#include <proxygen/httpserver/ResponseBuilder.h>
#include <ctime>
#include <spdlog/spdlog.h>
#include "../fiphoboserver_exception.h"
#include "s3_utilities/s3_utilities.h"
namespace fiphoboserver {
void PutRequestHandler::onRequest(
std::unique_ptr<proxygen::HTTPMessage> headers) noexcept
{
/* TODO log whatever this is */
if (downstream_ == nullptr) {
// can't push
return;
......@@ -27,9 +30,13 @@ void PutRequestHandler::onRequest(
/* Creating Bucket queries */
m_s3_header.set_headers(std::move(headers));
// m_s3_header.print_all_headers();
#ifndef NO_AUTHORISATION
spdlog::info("bucket: {}", m_s3_header.get_bucket());
spdlog::info("key: {}", m_s3_header.get_key_without_bucket());
// spdlog::debug("body length: {}", m_s3_header.get_body_length());
spdlog::debug("queries: {}", m_s3_header.get_queries());
#ifndef FIPHOBOSERVER_NO_AUTHORISATION
s3_utilities::Authorisation_status auth_status =
m_auth.authorise(m_s3_header);
if (auth_status != s3_utilities::Authorisation_status::waiting_for_payload
......@@ -42,6 +49,10 @@ void PutRequestHandler::onRequest(
.body(auth_error.get_xml(m_s3_header.get_key()))
.sendWithEOM();
m_stop_processing = true;
spdlog::warn(
"authorisation is invalid: {} ({})",
auth_error.https_error_identifier, auth_error.https_error_code);
return;
}
#endif
......@@ -61,6 +72,7 @@ void PutRequestHandler::onRequest(
* Add timestamp and content length to meta data and send it to backend
* through the stream
*/
spdlog::info("creating meta data");
auto metadata = m_s3_header.get_meta_data();
metadata["fiphobo:creation_time"] = std::to_string(std::time(nullptr));
metadata["fiphobo:content_length"] =
......@@ -68,6 +80,13 @@ void PutRequestHandler::onRequest(
metadata["fiphobo:bucket"] = m_s3_header.get_bucket();
m_stream->set_storage_meta_data(metadata);
spdlog::debug("meta data:");
std::for_each(
metadata.begin(), metadata.end(),
[&](std::pair<std::string, std::string> pair) {
spdlog::debug("{}: {}", pair.first, pair.second);
});
/*
* Tell stream to coordinate with backend to prepare for PUT operation
*/
......@@ -75,7 +94,7 @@ void PutRequestHandler::onRequest(
m_s3_header.get_body_length(), m_s3_header.get_key());
}
catch (const FIPhoboServerException& ex) {
std::cerr << "Caught exception: " << ex.what() << '\n';
spdlog::error("caught exception: {}", ex.what());
s3_utilities::s3_error_info error = s3_utilities::no_such_bucket;
proxygen::ResponseBuilder(downstream_)
.status(error.https_error_code, error.https_error_identifier)
......@@ -93,22 +112,25 @@ void PutRequestHandler::onBody(std::unique_ptr<folly::IOBuf> body) noexcept
}
try {
#ifndef NO_AUTHORISATION
#ifndef FIPHOBOSERVER_NO_AUTHORISATION
if (m_auth.get_status()
== s3_utilities::Authorisation_status::waiting_for_payload) {
// Add body as string to authentication object as payload
/* Add body as string to authentication object as payload */
std::string body_as_string = std::string(
reinterpret_cast<const char*>(body->data()), body->length());
m_auth.add_chunk(body_as_string);
}
#endif
spdlog::debug(
"sending {} bytes body chunk to backend storage", body->length());
/* Hand message body over to stream for PUT operation */
m_stream->put(std::move(body->data()), std::move(body->length()));
auto rc =
m_stream->put(std::move(body->data()), std::move(body->length()));
spdlog::debug("sent {} bytes", rc);
}
catch (const FIPhoboServerException& ex) {
std::cerr << "Caught an exception in put: " << ex.what() << '\n';
spdlog::error("caught exception in put: {}", ex.what());
s3_utilities::s3_error_info error =
s3_utilities::create_s3_error(ex.get_inner_error());
proxygen::ResponseBuilder(downstream_)
......@@ -128,10 +150,10 @@ void PutRequestHandler::onEOM() noexcept
return;
}
#ifndef NO_AUTHORISATION
#ifndef FIPHOBOSERVER_NO_AUTHORISATION
if (m_auth.get_status()
== s3_utilities::Authorisation_status::waiting_for_payload) {
// was waiting for payload, now I can try to authorise again
/* was waiting for payload, now I can try to authorise again */
if (m_auth.authorise(m_s3_header)
!= s3_utilities::Authorisation_status::valid) {
// TODO: Delete object from phobos or revert put! (Issue #45)
......@@ -143,6 +165,9 @@ void PutRequestHandler::onEOM() noexcept
.body(auth_error.get_xml(m_s3_header.get_key()))
.sendWithEOM();
spdlog::warn(
"authorisation is invalid: {} ({})",
auth_error.https_error_identifier, auth_error.https_error_code);
return;
}
}
......@@ -152,7 +177,7 @@ void PutRequestHandler::onEOM() noexcept
m_stream->finish_io();
}
catch (const FIPhoboServerException& ex) {
std::cerr << "Caught an exception in finish put: " << ex.what() << '\n';
spdlog::error("caught exception in finish put: {}", ex.what());
s3_utilities::s3_error_info error =
s3_utilities::create_s3_error(ex.get_inner_error());
proxygen::ResponseBuilder(downstream_)
......@@ -161,6 +186,7 @@ void PutRequestHandler::onEOM() noexcept
.sendWithEOM();
return;
}
spdlog::info("message body send complete");
proxygen::ResponseBuilder(downstream_).status(200, "OK").sendWithEOM();
}
......
......@@ -122,6 +122,7 @@ class S3_header {
///
size_t get_body_length() const
{
// TODO fixme
std::string content_length =
m_headers->getHeaders().getSingleOrEmpty("Content-Length");
return static_cast<size_t>(std::stoi(content_length));
......@@ -152,23 +153,6 @@ class S3_header {
return metadata;
}
///
/// @brief print all headers to std out
///
void print_all_headers() const
{
std::cout << "Printing all headers for " << m_headers->getPath()
<< "\n";
if (!m_headers->getQueryString().empty()) {
std::cout << "Queries: " << m_headers->getQueryString() << '\n';
}
m_headers->getHeaders().forEach(
[&](const std::string& header, const std::string& val) {
std::cout << header << ": " << val << "\n";
});
std::cout << std::flush;
}
///
/// @brief extract one header value from the headers
///
......
......@@ -2,6 +2,7 @@
#include "../fiphoboserver_exception.h"
#include <spdlog/spdlog.h>
#include <unistd.h>
#include <utility>
......@@ -24,6 +25,18 @@ Fifo::~Fifo()
close(m_fifo_descriptor[1]);
}
}
void Fifo::create_fifo()
{
int rc = pipe(m_fifo_descriptor);
if (rc == -1) {
throw IOException("Fifo::create_fifo", "mkfifo", errno);
return;
}
spdlog::debug(
"fifo descriptors: {}, {}", m_fifo_descriptor[0], m_fifo_descriptor[1]);
}
/* Simply pass along to the backend */
void Fifo::set_storage_meta_data(
std::map<std::string, std::string> meta_data) const
......@@ -92,19 +105,9 @@ ssize_t Fifo::get(void* buf, const size_t count) const
void Fifo::finish_io()
{
// will throw the inner exception if one occurred
/* will throw the inner exception if one occurred */
m_db_result.get();
}
void Fifo::create_fifo()
{
int rc = pipe(m_fifo_descriptor);
if (rc == -1) {
throw IOException("Fifo::create_fifo", "mkfifo", errno);
return;
}
}
} // namespace stream
} // namespace fiphoboserver
......@@ -40,6 +40,9 @@ void Config::define_options()
m_start->add_option(
"-t,--threads", m_thread_count, "number of threads to listen on");
m_start->add_option(
"-l,--logfile", m_log_filename, "name of file to write logs to");
m_parser.set_config("--config");
m_start->add_option(
"-w,--write-config", m_config_filename,
......@@ -58,7 +61,8 @@ cli_options Config::handle_arguments()
file.close();
}
return {m_http_port, m_http2_port, m_hostname, m_thread_count};
return {m_http_port, m_http2_port, m_hostname, m_thread_count,
m_log_filename};
}
} // namespace util
......
......@@ -17,6 +17,7 @@ struct cli_options {
int http2_port;
std::string ip;
int thread_count;
std::string log_filename;
};
///
......@@ -129,6 +130,11 @@ class Config {
/// @brief filename to write configuration options to
///
std::string m_config_filename;
///
/// @brief filename to write logs to
///
std::string m_log_filename = "/tmp/fiphoboserver_log.txt";
};