Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with
or
.
Download ZIP
Browse files

[http] HttpMessageProcessor: parser error logging improved

  • Loading branch information...
commit ab5385f00e21c7fc38e486ee651c65578b2494d9 1 parent 17210cd
@christianparpart authored
View
3  include/x0/http/HttpMessageProcessor.h
@@ -11,6 +11,7 @@
#include <x0/Buffer.h>
#include <x0/io/ChainFilter.h>
+#include <x0/LogMessage.h>
#include <x0/Defines.h>
#include <x0/Api.h>
@@ -157,6 +158,8 @@ class X0_API HttpMessageProcessor
bool isProcessingBody() const;
bool isContentExpected() const;
+ virtual void log(LogMessage&& msg) = 0;
+
public:
explicit HttpMessageProcessor(ParseMode mode);
virtual ~HttpMessageProcessor() {}
View
49 lib/http/HttpMessageProcessor.cpp
@@ -10,12 +10,17 @@
namespace x0 {
-#if 0
-# define TRACE(msg...) { printf("http-parser: " msg); printf("\n"); }
+#if !defined(NDEBUG)
+# define TRACE(level, fmt...) do { \
+ LogMessage msg(Severity::debug ## level, fmt); \
+ msg.addTag("parser"); \
+ log(std::move(msg)); \
+ } while (0)
#else
-# define TRACE(msg...)
+# define TRACE(level, msg...) do { } while (0)
#endif
+
//! Support messages using LF-only as linefeed instead of CRLF,
//! which is not HTTP conform.
#define X0_HTTP_SUPPORT_SHORT_LF 1
@@ -360,8 +365,8 @@ std::size_t HttpMessageProcessor::process(const BufferRef& chunk, size_t* out_np
size_t result = initialOutOffset;
size_t* nparsed = out_nparsed ? out_nparsed : &result;
- //TRACE("process(curState:%s): size: %ld: '%s'", state_str(), chunk.size(), chunk.str().c_str());
- TRACE("process(curState:%s): size: %ld", state_str(), chunk.size());
+ //TRACE(2, "process(curState:%s): size: %ld: '%s'", state_str(), chunk.size(), chunk.str().c_str());
+ TRACE(2, "process(curState:%s): size: %ld", state_str(), chunk.size());
#if 0
switch (state_) {
@@ -386,11 +391,11 @@ std::size_t HttpMessageProcessor::process(const BufferRef& chunk, size_t* out_np
#endif
while (i != e) {
-#if 0 // !defined(NDEBUG)
+#if !defined(NDEBUG)
if (std::isprint(*i)) {
- TRACE("parse: %4ld, 0x%02X (%c), %s", *nparsed, *i, *i, state_str());
+ TRACE(4, "parse: %4ld, 0x%02X (%c), %s", *nparsed, *i, *i, state_str());
} else {
- TRACE("parse: %4ld, 0x%02X, %s", *nparsed, *i, state_str());
+ TRACE(4, "parse: %4ld, 0x%02X, %s", *nparsed, *i, state_str());
}
#endif
@@ -539,7 +544,7 @@ std::size_t HttpMessageProcessor::process(const BufferRef& chunk, size_t* out_np
++*nparsed;
++i;
- TRACE("request-line: method=%s, entity=%s, vmaj=%d, vmin=%d",
+ TRACE(2, "request-line: method=%s, entity=%s, vmaj=%d, vmin=%d",
method_.str().c_str(), entity_.str().c_str(), versionMajor_, versionMinor_);
if (!onMessageBegin(method_, entity_, versionMajor_, versionMinor_)) {
@@ -561,7 +566,7 @@ std::size_t HttpMessageProcessor::process(const BufferRef& chunk, size_t* out_np
++*nparsed;
++i;
- TRACE("request-line: method=%s, entity=%s, vmaj=%d, vmin=%d",
+ TRACE(2, "request-line: method=%s, entity=%s, vmaj=%d, vmin=%d",
method_.str().c_str(), entity_.str().c_str(), versionMajor_, versionMinor_);
if (!onMessageBegin(method_, entity_, versionMajor_, versionMinor_)) {
@@ -696,7 +701,7 @@ std::size_t HttpMessageProcessor::process(const BufferRef& chunk, size_t* out_np
++*nparsed;
++i;
- //TRACE("status-line: HTTP/%d.%d, code=%d, message=%s", versionMajor_, versionMinor_, code_, message_.str().c_str());
+ //TRACE(2, "status-line: HTTP/%d.%d, code=%d, message=%s", versionMajor_, versionMinor_, code_, message_.str().c_str());
if (!onMessageBegin(versionMajor_, versionMinor_, code_, message_)) {
goto done;
}
@@ -857,11 +862,11 @@ std::size_t HttpMessageProcessor::process(const BufferRef& chunk, size_t* out_np
}
break;
case HEADER_VALUE_END: {
- TRACE("header: name='%s', value='%s'", name_.str().c_str(), value_.str().c_str());
+ TRACE(2, "header: name='%s', value='%s'", name_.str().c_str(), value_.str().c_str());
if (iequals(name_, "Content-Length")) {
contentLength_ = value_.toInt();
- TRACE("set content length to: %ld", contentLength_);
+ TRACE(2, "set content length to: %ld", contentLength_);
} else if (iequals(name_, "Transfer-Encoding")) {
if (iequals(value_, "chunked")) {
chunked_ = true;
@@ -891,7 +896,7 @@ std::size_t HttpMessageProcessor::process(const BufferRef& chunk, size_t* out_np
++i;
if (!onMessageHeaderEnd()) {
- TRACE("messageHeaderEnd returned false. returning `Aborted`-state");
+ TRACE(2, "messageHeaderEnd returned false. returning `Aborted`-state");
goto done;
}
@@ -914,7 +919,7 @@ std::size_t HttpMessageProcessor::process(const BufferRef& chunk, size_t* out_np
// body w/o content-length (allowed in simple MESSAGE types only)
BufferRef c(chunk.ref(*nparsed - initialOutOffset));
- //TRACE("prepared content-chunk (%ld bytes): %s", c.size(), c.str().c_str());
+ //TRACE(2, "prepared content-chunk (%ld bytes): %s", c.size(), c.str().c_str());
*nparsed += c.size();
i += c.size();
@@ -985,7 +990,7 @@ std::size_t HttpMessageProcessor::process(const BufferRef& chunk, size_t* out_np
if (*i != LF) {
state_ = SYNTAX_ERROR;
} else {
- //TRACE("content_length: %ld", contentLength_);
+ //TRACE(2, "content_length: %ld", contentLength_);
if (contentLength_ != 0)
state_ = CONTENT_CHUNK_BODY;
else
@@ -1049,11 +1054,11 @@ std::size_t HttpMessageProcessor::process(const BufferRef& chunk, size_t* out_np
break;
case SYNTAX_ERROR: {
#if !defined(NDEBUG)
- TRACE("parse: syntax error");
+ TRACE(1, "parse: syntax error");
if (std::isprint(*i)) {
- TRACE("parse: syntax error at nparsed: %ld, character: '%c'", *nparsed, *i);
+ TRACE(1, "parse: syntax error at nparsed: %ld, character: '%c'", *nparsed, *i);
} else {
- TRACE("parse: syntax error at nparsed: %ld, character: 0x%02X", *nparsed, *i);
+ TRACE(1, "parse: syntax error at nparsed: %ld, character: 0x%02X", *nparsed, *i);
}
chunk.dump("request chunk (at syntax error)");
#endif
@@ -1061,11 +1066,11 @@ std::size_t HttpMessageProcessor::process(const BufferRef& chunk, size_t* out_np
}
default:
#if !defined(NDEBUG)
- TRACE("parse: unknown state %i", state_);
+ TRACE(1, "parse: unknown state %i", state_);
if (std::isprint(*i)) {
- TRACE("parse: internal error at nparsed: %ld, character: '%c'", *nparsed, *i);
+ TRACE(1, "parse: internal error at nparsed: %ld, character: '%c'", *nparsed, *i);
} else {
- TRACE("parse: internal error at nparsed: %ld, character: 0x%02X", *nparsed, *i);
+ TRACE(1, "parse: internal error at nparsed: %ld, character: 0x%02X", *nparsed, *i);
}
Buffer::dump(chunk.data(), chunk.size(), "request chunk (at unknown state)");
#endif
View
10 plugins/cgi.cpp
@@ -90,6 +90,8 @@ class CgiScript :
static void runAsync(x0::HttpRequest *in, const std::string& hostprogram = "");
+ void log(x0::LogMessage&& msg);
+
private:
// CGI program's response message processor hooks
virtual bool onMessageHeader(const x0::BufferRef& name, const x0::BufferRef& value);
@@ -574,6 +576,14 @@ void CgiScript::onStderrAvailable(ev::io& /*w*/, int revents)
}
}
+void CgiScript::log(x0::LogMessage&& msg)
+{
+ if (request_) {
+ msg.addTag("cgi");
+ request_->log(std::move(msg));
+ }
+}
+
bool CgiScript::onMessageHeader(const x0::BufferRef& name, const x0::BufferRef& value)
{
TRACE("messageHeader(\"%s\", \"%s\")", name.str().c_str(), value.str().c_str());
View
6 plugins/director/Backend.cpp
@@ -51,6 +51,12 @@ Backend::~Backend()
delete healthMonitor_;
}
+void Backend::log(x0::LogMessage&& msg)
+{
+ msg.addTag(name_);
+ manager_->log(std::move(msg));
+}
+
size_t Backend::capacity() const
{
return capacity_;
View
2  plugins/director/Backend.h
@@ -56,6 +56,8 @@ class Backend
Backend(BackendManager* bm, const std::string& name, const x0::SocketSpec& socketSpec, size_t capacity, HealthMonitor* healthMonitor);
virtual ~Backend();
+ void log(x0::LogMessage&& msg);
+
void setJsonWriteCallback(const std::function<void(const Backend*, x0::JsonWriter&)>& callback);
void clearJsonWriteCallback();
View
5 plugins/director/BackendManager.cpp
@@ -24,3 +24,8 @@ BackendManager::~BackendManager()
{
}
+void BackendManager::log(x0::LogMessage&& msg)
+{
+ msg.addTag(name_);
+ worker_->log(std::move(msg));
+}
View
2  plugins/director/BackendManager.h
@@ -40,6 +40,8 @@ class BackendManager
BackendManager(x0::HttpWorker* worker, const std::string& name);
virtual ~BackendManager();
+ void log(x0::LogMessage&& msg);
+
x0::HttpWorker* worker() const { return worker_; }
const std::string name() const { return name_; }
View
32 plugins/director/FastCgiBackend.cpp
@@ -142,6 +142,11 @@ class FastCgiTransport : // {{{
virtual bool onMessageHeader(const x0::BufferRef& name, const x0::BufferRef& value);
virtual bool onMessageContent(const x0::BufferRef& content);
+ virtual void log(x0::LogMessage&& msg);
+
+ template<typename... Args>
+ void log(Severity severity, const char* fmt, Args&&... args);
+
void onWriteComplete();
static void onClientAbort(void *p);
@@ -155,9 +160,6 @@ class FastCgiTransport : // {{{
void onParam(const std::string& name, const std::string& value);
void inspect(x0::Buffer& out);
-
- template<typename... Args>
- void log(Severity severity, const char* fmt, Args&&... args);
}; // }}}
// {{{ FastCgiTransport impl
@@ -229,16 +231,6 @@ FastCgiTransport::~FastCgiTransport()
}
}
-template<typename... Args>
-inline void FastCgiTransport::log(Severity severity, const char* fmt, Args&&... args)
-{
- if (request_) {
- LogMessage msg(severity, fmt, args...);
- msg.addTag("fastcgi/%d", transportId_);
- request_->log(std::move(msg));
- }
-}
-
void FastCgiTransport::close()
{
TRACE(1, "Closing transport connection.");
@@ -718,6 +710,20 @@ bool FastCgiTransport::onMessageContent(const x0::BufferRef& content)
return false;
}
+void FastCgiTransport::log(x0::LogMessage&& msg)
+{
+ if (request_) {
+ msg.addTag("fastcgi/%d", transportId_);
+ request_->log(std::move(msg));
+ }
+}
+
+template<typename... Args>
+inline void FastCgiTransport::log(Severity severity, const char* fmt, Args&&... args)
+{
+ log(LogMessage(severity, fmt, args...));
+}
+
/**
* write-completion hook, invoked when a content chunk is written to the HTTP client.
*/
View
5 plugins/director/FastCgiHealthMonitor.cpp
@@ -100,6 +100,11 @@ class HttpRequestRec :
return true;
}
+
+ virtual void log(x0::LogMessage&& msg)
+ {
+ // TODO: in order to actually implement me, you must also pass the monitor I am working for
+ }
};
// }}}
View
6 plugins/director/HealthMonitor.cpp
@@ -214,6 +214,12 @@ void HealthMonitor::logFailure()
recheck();
}
+void HealthMonitor::log(x0::LogMessage&& msg)
+{
+ msg.addTag("monitor");
+ backend_->manager()->log(std::move(msg));
+}
+
/**
* Callback, invoked on successfully parsed response status line.
*/
View
2  plugins/director/HealthMonitor.h
@@ -112,6 +112,8 @@ class HealthMonitor :
virtual bool onMessageHeader(const x0::BufferRef& name, const x0::BufferRef& value);
virtual bool onMessageContent(const x0::BufferRef& chunk);
virtual bool onMessageEnd();
+
+ virtual void log(x0::LogMessage&& msg);
};
x0::JsonWriter& operator<<(x0::JsonWriter& json, const HealthMonitor& monitor);
View
10 plugins/director/HttpBackend.cpp
@@ -88,6 +88,8 @@ class HttpBackend::ProxyConnection :
virtual bool onMessageContent(const BufferRef& chunk);
virtual bool onMessageEnd();
+ virtual void log(x0::LogMessage&& msg);
+
public:
inline explicit ProxyConnection(HttpBackend* proxy);
~ProxyConnection();
@@ -395,6 +397,14 @@ bool HttpBackend::ProxyConnection::onMessageEnd()
return false;
}
+void HttpBackend::ProxyConnection::log(x0::LogMessage&& msg)
+{
+ if (request_) {
+ msg.addTag("http-backend");
+ request_->log(std::move(msg));
+ }
+}
+
void HttpBackend::ProxyConnection::io(Socket* s, int revents)
{
TRACE("io(0x%04x)", revents);
View
9 plugins/fastcgi.cpp
@@ -194,6 +194,14 @@ class CgiTransport : // {{{
void inspect(x0::Buffer& out);
+ virtual void log(x0::LogMessage&& msg)
+ {
+ if (request_) {
+ msg.addTag("fastcgi/%llu", transportId_);
+ request_->log(std::move(msg));
+ }
+ }
+
template<typename... Args>
void log(x0::Severity severity, const char* fmt, Args&&... args)
{
@@ -207,7 +215,6 @@ class CgiTransport : // {{{
request_->log(severity, msg.c_str(), args...);
}
}
-
}; // }}}
class CgiContext //{{{
View
7 plugins/proxy.cpp
@@ -92,6 +92,13 @@ class ProxyConnection :
virtual bool onMessageContent(const x0::BufferRef& chunk);
virtual bool onMessageEnd();
+ virtual void log(x0::LogMessage&& msg)
+ {
+ if (request_) {
+ msg.addTag("proxy");
+ request_->log(std::move(msg));
+ }
+ }
public:
inline ProxyConnection();
~ProxyConnection();
View
4 tests/message_processor_test.cpp
@@ -89,6 +89,10 @@ class HttpMessageProcessor_component : // {{{
return true;
}
+
+ virtual void log(x0::LogMessage&& msg)
+ {
+ }
}; // }}}
class HttpMessageProcessor_test :
Please sign in to comment.
Something went wrong with that request. Please try again.