Hawkin
/
arangodb
mirror of https://gitee.com/bigwinds/arangodb
1
0
Fork 0
Code Issues Projects Releases Wiki Activity

improve logging

This commit is contained in:
Jan Christoph Uhde 2016-08-26 16:22:49 +02:00
parent d635b720b0
commit 8e56b1df7d
2 changed files with 76 additions and 37 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

75
arangod/GeneralServer/VppCommTask.cpp
View File

@ -167,6 +167,7 @@ VppCommTask::VppCommTask(GeneralServer* server, TRI_socket_t sock,
// loose information during a resize
// connectionStatisticsAgentSetVpp();
_agents.emplace(std::make_pair(0UL, RequestStatisticsAgent(true)));
getAgent(0UL)->acquire();
}
void VppCommTask::addResponse(VppResponse* response) {
@ -183,7 +184,8 @@ void VppCommTask::addResponse(VppResponse* response) {
slices.push_back(builder.slice());
}
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "got response:";
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "VppCommTask: "
<< "created response:";
for (auto const& slice : slices) {
try {
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << slice.toJson();
@ -202,11 +204,22 @@ void VppCommTask::addResponse(VppResponse* response) {
// used with _writeBuffers
auto buffer = createChunkForNetworkSingle(slices, id);
double const totalTime = getAgent(id)->elapsedSinceReadStart();
addWriteBuffer(std::move(buffer), getAgent(id));
_agents.erase(id);
if (!id) {
_agents.emplace(std::make_pair(0UL, RequestStatisticsAgent(true)));
// and give some request information
LOG_TOPIC(INFO, Logger::REQUESTS)
<< "\"vpp-request-end\",\"" << (void*)this << "\",\""
<< _connectionInfo.clientAddress << "\",\""
<< VppRequest::translateVersion(_protocolVersion) << "\","
<< static_cast<int>(response->responseCode()) << ","
<< "\"," << Logger::FIXED(totalTime, 6);
if (id) {
_agents.erase(id);
} else {
getAgent(0UL)->acquire();
}
}
@ -286,8 +299,13 @@ bool VppCommTask::processRead() {
if (chunkHeader._isFirst && chunkHeader._chunk == 1) {
_agents.emplace(
std::make_pair(chunkHeader._messageID, RequestStatisticsAgent(true)));
getAgent(chunkHeader._messageID)->requestStatisticsAgentSetReadStart();
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "chunk contains single message";
auto agent = getAgent(chunkHeader._messageID);
agent->acquire();
agent->requestStatisticsAgentSetReadStart();
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "VppCommTask: "
<< "chunk contains single message";
std::size_t payloads = 0;
try {
@ -296,13 +314,15 @@ bool VppCommTask::processRead() {
handleSimpleError(rest::ResponseCode::BAD,
TRI_ERROR_ARANGO_DATABASE_NOT_FOUND, e.what(),
chunkHeader._messageID);
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "VPack Validation failed!"
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "VppCommTask: "
<< "VPack Validation failed!"
<< e.what();
closeTask(rest::ResponseCode::BAD);
return false;
} catch (...) {
handleSimpleError(rest::ResponseCode::BAD, chunkHeader._messageID);
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "VPack Validation failed!";
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "VppCommTask: "
<< "VPack Validation failed!";
closeTask(rest::ResponseCode::BAD);
return false;
}
@ -326,10 +346,16 @@ bool VppCommTask::processRead() {
if (chunkHeader._isFirst) { // first chunk of multi chunk message
_agents.emplace(
std::make_pair(chunkHeader._messageID, RequestStatisticsAgent(true)));
getAgent(chunkHeader._messageID)->requestStatisticsAgentSetReadStart();
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "chunk starts a new message";
auto agent = getAgent(chunkHeader._messageID);
agent->acquire();
agent->requestStatisticsAgentSetReadStart();
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "VppCommTask: "
<< "chunk starts a new message";
if (incompleteMessageItr != _incompleteMessages.end()) {
LOG_TOPIC(DEBUG, Logger::COMMUNICATION)
<< "VppCommTask: "
<< "Message should be first but is already in the Map of incomplete "
"messages";
closeTask(rest::ResponseCode::BAD);
@ -344,16 +370,19 @@ bool VppCommTask::processRead() {
auto insertPair = _incompleteMessages.emplace(
std::make_pair(chunkHeader._messageID, std::move(message)));
if (!insertPair.second) {
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "insert failed";
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "VppCommTask: "
<< "insert failed";
closeTask(rest::ResponseCode::BAD);
return false;
}
// CASE 2b: chunk continues a message
} else { // followup chunk of some mesage
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "chunk continues a message";
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "VppCommTask: "
<< "chunk continues a message";
if (incompleteMessageItr == _incompleteMessages.end()) {
LOG_TOPIC(DEBUG, Logger::COMMUNICATION)
<< "VppCommTask: "
<< "found message without previous part";
closeTask(rest::ResponseCode::BAD);
return false;
@ -366,7 +395,8 @@ bool VppCommTask::processRead() {
// MESSAGE COMPLETE
if (im._currentChunk == im._numberOfChunks - 1 /* zero based counting */) {
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "chunk completes a message";
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "VppCommTask: "
<< "chunk completes a message";
std::size_t payloads = 0;
try {
@ -379,13 +409,15 @@ bool VppCommTask::processRead() {
handleSimpleError(rest::ResponseCode::BAD,
TRI_ERROR_ARANGO_DATABASE_NOT_FOUND, e.what(),
chunkHeader._messageID);
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "VPack Validation failed!"
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "VppCommTask: "
<< "VPack Validation failed!"
<< e.what();
closeTask(rest::ResponseCode::BAD);
return false;
} catch (...) {
handleSimpleError(rest::ResponseCode::BAD, chunkHeader._messageID);
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "VPack Validation failed!";
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "VppCommTask: "
<< "VPack Validation failed!";
closeTask(rest::ResponseCode::BAD);
return false;
}
@ -398,6 +430,7 @@ bool VppCommTask::processRead() {
getAgent(chunkHeader._messageID)->requestStatisticsAgentSetReadEnd();
}
LOG_TOPIC(DEBUG, Logger::COMMUNICATION)
<< "VppCommTask: "
<< "chunk does not complete a message";
}
@ -416,14 +449,22 @@ bool VppCommTask::processRead() {
if (doExecute) {
VPackSlice header = message.header();
LOG_TOPIC(DEBUG, Logger::COMMUNICATION) << "got request:"
<< header.toJson();
LOG_TOPIC(DEBUG, Logger::REQUESTS) << "\"vpp-request-header\",\""
<< "\"," << message.header().toJson()
<< "\"";
LOG_TOPIC(DEBUG, Logger::REQUESTS) << "\"vpp-request-payload\",\""
<< "\"," << message.payload().toJson()
<< "\"";
int type = meta::underlyingValue(rest::RequestType::ILLEGAL);
try {
type = header.at(1).getInt();
} catch (std::exception const& e) {
handleSimpleError(rest::ResponseCode::BAD, chunkHeader._messageID);
LOG_TOPIC(DEBUG, Logger::COMMUNICATION)
<< "VppCommTask: "
<< std::string("VPack Validation failed!") + e.what();
closeTask(rest::ResponseCode::BAD);
return false;

38
arangod/V8Server/v8-actions.cpp
View File

@ -24,6 +24,10 @@
#include "v8-actions.h"
#include "V8/v8-vpack.h"
#include <velocypack/Builder.h>
#include <velocypack/Parser.h>
#include <velocypack/Validator.h>
#include <velocypack/velocypack-aliases.h>
#include "Actions/ActionFeature.h"
#include "Actions/actions.h"
#include "Basics/MutexLocker.h"
@ -49,10 +53,6 @@
#include "V8Server/v8-vocbase.h"
#include "VocBase/ticks.h"
#include "VocBase/vocbase.h"
#include <velocypack/Validator.h>
#include <velocypack/Builder.h>
#include <velocypack/Parser.h>
#include <velocypack/velocypack-aliases.h>
#include <iostream>
@ -424,8 +424,8 @@ static v8::Handle<v8::Object> RequestCppToV8(v8::Isolate* isolate,
// auto result = TRI_VPackToV8(isolate, slice);
std::string jsonString = slice.toJson();
LOG_TOPIC(DEBUG, Logger::COMMUNICATION)
<< "json handed into v8 request:\n" << jsonString;
LOG_TOPIC(DEBUG, Logger::REQUESTS) << "json handed into v8 request:\n"
<< jsonString;
// V8Buffer* buffer =
// V8Buffer::New(isolate, slice.startAs<char>(),
@ -715,7 +715,8 @@ static void ResponseV8ToCpp(v8::Isolate* isolate, TRI_v8_global_t const* v8g,
// json could not be converted
// there was no json - change content type?
LOG_TOPIC(DEBUG, Logger::COMMUNICATION)
<< "failed to parse json:\n" << out;
<< "failed to parse json:\n"
<< out;
}
}
@ -728,11 +729,9 @@ static void ResponseV8ToCpp(v8::Isolate* isolate, TRI_v8_global_t const* v8g,
response->setContentType(rest::ContentType::VPACK);
response->setPayload(builder.slice(), true);
break;
}
default: {
throw std::logic_error("unknown transport type");
}
default: { throw std::logic_error("unknown transport type"); }
}
bodySet = true;
}
@ -757,8 +756,7 @@ static void ResponseV8ToCpp(v8::Isolate* isolate, TRI_v8_global_t const* v8g,
"': " + TRI_last_error();
httpResponse->body().appendText(msg.c_str(), msg.size());
response->setResponseCode(
rest::ResponseCode::SERVER_ERROR);
response->setResponseCode(rest::ResponseCode::SERVER_ERROR);
}
} break;
@ -936,8 +934,9 @@ static TRI_action_result_t ExecuteActionVocbase(
// TODO how to generalize this?
if (response->transportType() ==
Endpoint::TransportType::HTTP) { // FIXME
((HttpResponse*)response)->body().appendText(
TRI_StringifyV8Exception(isolate, &tryCatch));
((HttpResponse*)response)
->body()
.appendText(TRI_StringifyV8Exception(isolate, &tryCatch));
}
} else {
v8g->_canceled = true;
@ -1368,8 +1367,7 @@ void TRI_InitV8Actions(v8::Isolate* isolate, v8::Handle<v8::Context> context) {
static bool clusterSendToAllServers(
std::string const& dbname,
std::string const& path, // Note: Has to be properly encoded!
arangodb::rest::RequestType const& method,
std::string const& body) {
arangodb::rest::RequestType const& method, std::string const& body) {
ClusterInfo* ci = ClusterInfo::instance();
ClusterComm* cc = ClusterComm::instance();
std::string url = "/_db/" + StringUtils::urlEncode(dbname) + "/" + path;
@ -1552,9 +1550,9 @@ static void JS_DebugClearFailAt(
}
std::string dbname(v8g->_vocbase->name());
int res = clusterSendToAllServers(
dbname, "_admin/debug/failat",
arangodb::rest::RequestType::DELETE_REQ, "");
int res =
clusterSendToAllServers(dbname, "_admin/debug/failat",
arangodb::rest::RequestType::DELETE_REQ, "");
if (res != TRI_ERROR_NO_ERROR) {
TRI_V8_THROW_EXCEPTION(res);
}