TEST(PapiTests, trace_basic) {
PapiTracer pt;
pt.addEvent("PAPI_TOT_CYC");
pt.start();
work();
pt.stop();
#ifdef USE_PAPI_TRACE
ASSERT_GT(pt.value("PAPI_TOT_CYC"), 0);
#endif
}
const _PlanOperation *_PlanOperation::execute() {
epoch_t startTime = get_epoch_nanoseconds();
refreshInput();
setupPlanOperation();
PapiTracer pt;
pt.addEvent("PAPI_TOT_CYC");
pt.addEvent(getEvent());
pt.start();
executePlanOperation();
pt.stop();
teardownPlanOperation();
epoch_t endTime = get_epoch_nanoseconds();
std::string threadId = boost::lexical_cast<std::string>(std::this_thread::get_id());
if (_performance_attr != nullptr)
*_performance_attr = (performance_attributes_t) {
pt.value("PAPI_TOT_CYC"), pt.value(getEvent()), getEvent() , planOperationName(), _operatorId, startTime, endTime, threadId
};
setState(OpSuccess);
return this;
}
TEST(PapiTests, trace_nested_with_disabled_inner) {
PapiTracer outer;
outer.addEvent("PAPI_TOT_CYC");
outer.start();
PapiTracer inner;
inner.addEvent("NO_PAPI");
inner.start();
work();
inner.stop();
outer.stop();
}
const PlanOperation* PlanOperation::execute() {
const bool recordPerformance = _performance_attr != nullptr;
// Check if we really need this
epoch_t startTime = 0;
if (recordPerformance)
startTime = get_epoch_nanoseconds();
PapiTracer pt;
// Start the execution
refreshInput();
setupPlanOperation();
if (recordPerformance) {
pt.addEvent("PAPI_TOT_CYC");
pt.addEvent(getEvent());
pt.start();
}
executePlanOperation();
if (recordPerformance)
pt.stop();
teardownPlanOperation();
if (recordPerformance) {
epoch_t endTime = get_epoch_nanoseconds();
std::string threadId = boost::lexical_cast<std::string>(std::this_thread::get_id());
size_t cardinality;
if (getResultTable() != empty_result)
cardinality = getResultTable()->size();
else
// the cardinality is max(size_t) by convention if there is no return table
cardinality = std::numeric_limits<size_t>::max();
*_performance_attr = (performance_attributes_t) {pt.value("PAPI_TOT_CYC"), pt.value(getEvent()), getEvent(),
planOperationName(), _operatorId, startTime,
endTime, threadId, cardinality};
}
setState(OpSuccess);
return this;
}
Json::Value ResponseTask::generateResponseJson() {
Json::Value response;
epoch_t responseStart = _recordPerformanceData ? get_epoch_nanoseconds() : 0;
PapiTracer pt;
pt.addEvent("PAPI_TOT_CYC");
if (_recordPerformanceData)
pt.start();
auto predecessor = getResultTask();
const auto& result = predecessor->getResultTable();
if (getState() != OpFail) {
if (!_isAutoCommit) {
response["session_context"] =
std::to_string(_txContext.tid).append(" ").append(std::to_string(_txContext.lastCid));
}
if (result) {
// Make header
Json::Value json_header(Json::arrayValue);
for (unsigned col = 0; col < result->columnCount(); ++col) {
Json::Value colname(result->nameOfColumn(col));
json_header.append(colname);
}
// Copy the complete result
response["real_size"] = result->size();
response["rows"] = generateRowsJson(result, _transmitLimit, _transmitOffset);
response["header"] = json_header;
}
////////////////////////////////////////////////////////////////////////////////////////
// Copy Performance Data
if (_recordPerformanceData) {
Json::Value json_perf(Json::arrayValue);
for (const auto& attr : performance_data) {
Json::Value element;
element["papi_event"] = Json::Value(attr->papiEvent);
element["duration"] = Json::Value((Json::UInt64)attr->duration);
element["data"] = Json::Value((Json::UInt64)attr->data);
element["name"] = Json::Value(attr->name);
element["id"] = Json::Value(attr->operatorId);
element["startTime"] = Json::Value((double)(attr->startTime - queryStart) / 1000000);
element["endTime"] = Json::Value((double)(attr->endTime - queryStart) / 1000000);
element["executingThread"] = Json::Value(attr->executingThread);
element["lastCore"] = Json::Value(attr->core);
element["lastNode"] = Json::Value(attr->node);
// Put null for in/outRows if -1 was set
element["inRows"] = attr->in_rows ? Json::Value(*(attr->in_rows)) : Json::Value();
element["outRows"] = attr->out_rows ? Json::Value(*(attr->out_rows)) : Json::Value();
if (_getSubQueryPerformanceData) {
element["subQueryPerformanceData"] = _scriptOperation->getSubQueryPerformanceData();
}
json_perf.append(element);
}
pt.stop();
Json::Value responseElement;
responseElement["duration"] = Json::Value((Json::UInt64)pt.value("PAPI_TOT_CYC"));
responseElement["name"] = Json::Value("ResponseTask");
responseElement["id"] = Json::Value("respond");
responseElement["startTime"] = Json::Value((double)(responseStart - queryStart) / 1000000);
responseElement["endTime"] = Json::Value((double)(get_epoch_nanoseconds() - queryStart) / 1000000);
std::string threadId = boost::lexical_cast<std::string>(std::this_thread::get_id());
responseElement["executingThread"] = Json::Value(threadId);
responseElement["lastCore"] = Json::Value(getCurrentCore());
responseElement["lastNode"] = Json::Value(getCurrentNode());
std::optional<size_t> result_size;
if (result) {
result_size = result->size();
}
responseElement["inRows"] = result_size ? Json::Value(*result_size) : Json::Value();
responseElement["outRows"] = Json::Value();
json_perf.append(responseElement);
response["performanceData"] = json_perf;
}
Json::Value jsonKeys(Json::arrayValue);
for (const auto& x : _generatedKeyRefs) {
for (const auto& key : *x) {
Json::Value element(key);
jsonKeys.append(element);
}
}
response["generatedKeys"] = jsonKeys;
response["affectedRows"] = Json::Value(_affectedRows);
if (_getSubQueryPerformanceData) {
response["subQueryDataflow"] = _scriptOperation->getSubQueryDataflow();
}
}
LOG4CXX_DEBUG(_logger, "Table Use Count: " << result.use_count());
return response;
}
void ResponseTask::operator()() {
epoch_t responseStart = get_epoch_nanoseconds();
Json::Value response;
if (getDependencyCount() > 0) {
PapiTracer pt;
pt.addEvent("PAPI_TOT_CYC");
pt.start();
auto predecessor = getResultTask();
const auto& result = predecessor->getResultTable();
if (predecessor->getState() != OpFail) {
if (result) {
// Make header
Json::Value json_header(Json::arrayValue);
for (unsigned col = 0; col < result->columnCount(); ++col) {
Json::Value colname(result->nameOfColumn(col));
json_header.append(colname);
}
// Copy the complete result
response["real_size"] = result->size();
response["rows"] = generateRowsJson(result, _transmitLimit);
response["header"] = json_header;
}
// Copy Performance Data
Json::Value json_perf(Json::arrayValue);
for (const auto & attr: performance_data) {
Json::Value element;
element["papi_event"] = Json::Value(attr->papiEvent);
element["duration"] = Json::Value((Json::UInt64) attr->duration);
element["data"] = Json::Value((Json::UInt64) attr->data);
element["name"] = Json::Value(attr->name);
element["id"] = Json::Value(attr->operatorId);
element["startTime"] = Json::Value((double)(attr->startTime - queryStart) / 1000000);
element["endTime"] = Json::Value((double)(attr->endTime - queryStart) / 1000000);
element["executingThread"] = Json::Value(attr->executingThread);
json_perf.append(element);
}
pt.stop();
Json::Value responseElement;
responseElement["duration"] = Json::Value((Json::UInt64) pt.value("PAPI_TOT_CYC"));
responseElement["name"] = Json::Value("ResponseTask");
responseElement["id"] = Json::Value("respond");
responseElement["startTime"] = Json::Value((double)(responseStart - queryStart) / 1000000);
responseElement["endTime"] = Json::Value((double)(get_epoch_nanoseconds() - queryStart) / 1000000);
std::string threadId = boost::lexical_cast<std::string>(std::this_thread::get_id());
responseElement["executingThread"] = Json::Value(threadId);
json_perf.append(responseElement);
response["performanceData"] = json_perf;
} else {
LOG4CXX_ERROR(_logger, "Error during plan execution: " << predecessor->getErrorMessage());
response["error"] = predecessor->getErrorMessage();
}
LOG4CXX_DEBUG(_logger, "Table Use Count: " << result.use_count());
} else {
response["error"] = "Query parsing failed, see server error log";
}
connection->respond(response.toStyledString());
}
TEST(PapiTests, trace_nested_with_enabled_inner) {
PapiTracer outer;
outer.addEvent("PAPI_TOT_CYC");
outer.start();
PapiTracer inner;
inner.addEvent("PAPI_TOT_CYC");
inner.addEvent("NO_PAPI");
inner.start();
work();
inner.stop();
#ifdef USE_PAPI_TRACE
ASSERT_EQ(inner.value("PAPI_TOT_CYC"), 0) << "Disabled counters should return zero";
#endif
outer.stop();
#ifdef USE_PAPI_TRACE
ASSERT_GT(outer.value("PAPI_TOT_CYC"), 0);
#endif
}
