Giao diện
📊 High-Performance Logging Observability
std::cout is killing your performance. Blocking I/O can slow HPN Tunnel by 50%.
Master async logging, structured logging, and request tracing.
Master async logging, structured logging, and request tracing.
The Problem: std::cout is Blocking (@[/observability])
cpp
// ❌ BLOCKING LOGGING — Every log call blocks the thread!
void ProcessPacket(const Packet& packet) {
std::cout << "[" << GetTimestamp() << "] "
<< "Processing packet " << packet.id_
<< " from " << packet.source_ip_
<< std::endl; // FLUSH! Blocks until kernel writes!
// ... actual work ...
}Benchmark: cout vs spdlog
┌─────────────────────────────────────────────────────────────────────────┐
│ LOGGING PERFORMANCE COMPARISON │
├─────────────────────────────────────────────────────────────────────────┤
│ │
│ Method Time per log Throughput impact │
│ ────────────────── ──────────── ───────────────── │
│ std::cout + endl ~10 µs ↓ 50% throughput │
│ std::cout (no flush) ~2 µs ↓ 20% throughput │
│ printf ~1.5 µs ↓ 15% throughput │
│ spdlog sync ~0.5 µs ↓ 5% throughput │
│ spdlog async ~0.1 µs ↓ 1% throughput ✅ │
│ No logging 0 µs Baseline │
│ │
│ HPN Tunnel @ 100K packets/s: │
│ • std::cout: 100K × 10µs = 1 second/second wasted on logging! │
│ • spdlog async: 100K × 0.1µs = 10ms/second (acceptable) │
│ │
└─────────────────────────────────────────────────────────────────────────┘spdlog — Fast C++ Logging Library
Installation
bash
# Via Conan
conan install spdlog/1.12.0@
# Via Vcpkg
vcpkg install spdlog
# Via apt
sudo apt install libspdlog-devCMake Integration
cmake
find_package(spdlog REQUIRED)
target_link_libraries(myapp PRIVATE spdlog::spdlog)Basic spdlog Usage
cpp
#include <spdlog/spdlog.h>
int main() {
// Default logger (stdout, sync)
spdlog::info("Welcome to spdlog!");
spdlog::warn("Easy padding in numbers like {:08d}", 12);
spdlog::error("Some error message with arg: {}", 42);
// Change log level
spdlog::set_level(spdlog::level::debug);
spdlog::debug("This will be printed");
// Format with fmt library
spdlog::info("User {} logged in from {}", "john", "192.168.1.1");
return 0;
}Output
[2024-01-15 10:30:45.123] [info] Welcome to spdlog!
[2024-01-15 10:30:45.123] [warning] Easy padding in numbers like 00000012
[2024-01-15 10:30:45.123] [error] Some error message with arg: 42
[2024-01-15 10:30:45.123] [debug] This will be printed
[2024-01-15 10:30:45.124] [info] User john logged in from 192.168.1.1Async Logging — Non-Blocking
cpp
#include <spdlog/spdlog.h>
#include <spdlog/async.h>
#include <spdlog/sinks/basic_file_sink.h>
#include <spdlog/sinks/rotating_file_sink.h>
int main() {
// Initialize async logging
spdlog::init_thread_pool(8192, 1); // Queue size, worker threads
// Create async file logger
auto async_file = spdlog::basic_logger_mt<spdlog::async_factory>(
"async_file_logger",
"/var/log/myapp/app.log"
);
// Use it
async_file->info("This is logged asynchronously!");
// Set as default logger
spdlog::set_default_logger(async_file);
spdlog::info("Now using async by default");
// Flush before exit
spdlog::shutdown();
return 0;
}┌─────────────────────────────────────────────────────────────────────────┐
│ ASYNC LOGGING ARCHITECTURE │
├─────────────────────────────────────────────────────────────────────────┤
│ │
│ Main Thread Background Thread │
│ ──────────── ───────────────── │
│ │
│ ┌───────────────┐ ┌───────────────┐ │
│ │ spdlog::info()│ enqueue │ Worker Thread │ │
│ │ (returns │ ──────────► │ (dequeue & │ ───► File/Network │
│ │ immediately) │ │ write) │ │
│ └───────────────┘ └───────────────┘ │
│ │ ▲ │
│ │ │ │
│ ▼ │ │
│ ┌─────────────────────────────────────┴──┐ │
│ │ Lock-free Queue (8192 slots) │ │
│ └────────────────────────────────────────┘ │
│ │
│ → Main thread never blocks on I/O │
│ → Logs written to disk in batches (efficient) │
│ │
└─────────────────────────────────────────────────────────────────────────┘Rotating File Logs
cpp
#include <spdlog/sinks/rotating_file_sink.h>
// Create rotating file logger
// Max 5MB per file, keep 3 rotated files
auto rotating = spdlog::rotating_logger_mt(
"rotating_logger",
"/var/log/myapp/app.log",
5 * 1024 * 1024, // 5 MB
3 // Keep 3 files
);
// Files created:
// app.log (current)
// app.1.log (previous)
// app.2.log (older)
// app.3.log (oldest, deleted when new one created)Structured Logging (JSON)
Why Structured Logging?
┌─────────────────────────────────────────────────────────────────────────┐
│ PLAIN TEXT vs STRUCTURED LOGGING │
├─────────────────────────────────────────────────────────────────────────┤
│ │
│ PLAIN TEXT: │
│ ───────────── │
│ [INFO] User john logged in from 192.168.1.1 at 2024-01-15 10:30:45 │
│ │
│ Problems: │
│ • Hard to parse programmatically │
│ • Different formats per developer │
│ • grep/awk required for analysis │
│ │
│ STRUCTURED (JSON): │
│ ───────────────── │
│ {"ts":"2024-01-15T10:30:45.123Z","level":"info", │
│ "msg":"user_login","user":"john","ip":"192.168.1.1"} │
│ │
│ Benefits: │
│ • Machine parseable │
│ • Searchable in ELK/Datadog/Splunk │
│ • Consistent schema │
│ • Easy aggregation │
│ │
└─────────────────────────────────────────────────────────────────────────┘JSON Logging with spdlog
cpp
#include <spdlog/spdlog.h>
#include <spdlog/sinks/basic_file_sink.h>
#include <nlohmann/json.hpp>
using json = nlohmann::json;
class JsonFormatter : public spdlog::formatter {
public:
void format(const spdlog::details::log_msg& msg,
spdlog::memory_buf_t& dest) override {
json j;
j["ts"] = std::chrono::system_clock::now().time_since_epoch().count();
j["level"] = spdlog::level::to_string_view(msg.level).data();
j["msg"] = std::string(msg.payload.begin(), msg.payload.end());
j["logger"] = std::string(msg.logger_name.begin(),
msg.logger_name.end());
auto str = j.dump() + "\n";
dest.append(str.data(), str.data() + str.size());
}
std::unique_ptr<formatter> clone() const override {
return std::make_unique<JsonFormatter>(*this);
}
};
// Usage
auto logger = spdlog::basic_logger_mt("json_logger", "app.jsonl");
logger->set_formatter(std::make_unique<JsonFormatter>());
logger->info("User login");Request ID Tracing
cpp
#include <spdlog/spdlog.h>
#include <string>
#include <random>
// Generate unique request ID
std::string GenerateRequestId() {
static std::random_device rd;
static std::mt19937 gen(rd());
static std::uniform_int_distribution<uint64_t> dis;
std::stringstream ss;
ss << std::hex << dis(gen);
return ss.str();
}
// Thread-local request context
thread_local std::string current_request_id;
void SetRequestId(const std::string& id) {
current_request_id = id;
}
// Custom formatter with request ID
class RequestIdFormatter : public spdlog::formatter {
public:
void format(const spdlog::details::log_msg& msg,
spdlog::memory_buf_t& dest) override {
auto formatted = fmt::format(
"[{}] [{}] [req:{}] {}\n",
msg.time,
spdlog::level::to_string_view(msg.level),
current_request_id.empty() ? "-" : current_request_id,
std::string_view(msg.payload.data(), msg.payload.size())
);
dest.append(formatted.data(), formatted.data() + formatted.size());
}
std::unique_ptr<formatter> clone() const override {
return std::make_unique<RequestIdFormatter>(*this);
}
};
// Usage in request handler
void HandleRequest(const Request& req) {
auto request_id = GenerateRequestId();
SetRequestId(request_id);
spdlog::info("Request received"); // [req:a1b2c3d4] Request received
ProcessAuth(); // [req:a1b2c3d4] Auth check
ProcessData(); // [req:a1b2c3d4] Data processed
SendResponse(); // [req:a1b2c3d4] Response sent
spdlog::info("Request completed");
}┌─────────────────────────────────────────────────────────────────────────┐
│ REQUEST TRACING ACROSS SERVICES │
├─────────────────────────────────────────────────────────────────────────┤
│ │
│ API Gateway Auth Service │
│ ───────────── ───────────── │
│ [req:abc123] Received [req:abc123] Validating │
│ [req:abc123] Forward to Auth [req:abc123] Token OK │
│ [req:abc123] Auth response OK [req:abc123] Response sent │
│ │
│ Database Service All logs with abc123 │
│ ───────────────── ───────────────────── │
│ [req:abc123] Query started grep "abc123" *.log │
│ [req:abc123] Query completed to trace entire request! │
│ [req:abc123] Response sent │
│ │
└─────────────────────────────────────────────────────────────────────────┘Log Levels Strategy
cpp
// Define when to use each level
spdlog::trace("Detailed trace for debugging"); // Dev only
spdlog::debug("Debug info for development"); // Dev only
spdlog::info("Important events"); // Production
spdlog::warn("Something unexpected"); // Production
spdlog::error("Something failed"); // Production + Alert
spdlog::critical("System is dying!"); // Production + Page on-call┌─────────────────────────────────────────────────────────────────────────┐
│ LOG LEVEL STRATEGY │
├─────────────────────────────────────────────────────────────────────────┤
│ │
│ Level Production Alert When to Use │
│ ───── ────────── ───── ───────────────────────────────── │
│ TRACE ❌ Off ❌ Detailed debug (loop iterations) │
│ DEBUG ❌ Off ❌ Development debugging │
│ INFO ✅ On ❌ Request start/end, milestones │
│ WARN ✅ On ⚠️ Slack Degraded but working │
│ ERROR ✅ On 🚨 Slack Operation failed, needs attention │
│ CRITICAL ✅ On 📟 PagerDuty System down, page on-call │
│ │
│ In production: spdlog::set_level(spdlog::level::info); │
│ In development: spdlog::set_level(spdlog::level::trace); │
│ │
└─────────────────────────────────────────────────────────────────────────┘Best Practices
┌─────────────────────────────────────────────────────────────────────────┐
│ LOGGING BEST PRACTICES │
├─────────────────────────────────────────────────────────────────────────┤
│ │
│ ✅ DO │
│ ───── │
│ • Use async logging for hot paths │
│ • Include request ID in every log │
│ • Use structured logging (JSON) for production │
│ • Rotate logs (don't fill disk) │
│ • Flush logs before crash (spdlog::shutdown()) │
│ │
│ ❌ DON'T │
│ ─────── │
│ • Don't use std::cout in production code │
│ • Don't log sensitive data (passwords, tokens) │
│ • Don't log in tight loops without throttling │
│ • Don't skip log levels (use the right one) │
│ │
│ 📊 WHAT TO LOG │
│ ─────────────── │
│ • Request ID, User ID │
│ • Operation name │
│ • Duration (for performance tracking) │
│ • Result (success/failure) │
│ • Error details (but not stack traces in JSON) │
│ │
└─────────────────────────────────────────────────────────────────────────┘