Bug 1586132 - Use jsoncpp to test profiler output in Profiler.Markers gtest - r=gregtatum

This does not test more markers than before. But instead of searching for
strings in the raw json, expected values are checked in the parsed output
profile.

Also some `ASSERT_...` tests could be changed to `EXPECT_...`, because their
failures would not prevent running more of the test.

Differential Revision: https://phabricator.services.mozilla.com/D48326

--HG--
extra : moz-landing-system : lando
This commit is contained in:
Gerald Squelart 2019-10-08 02:16:00 +00:00
Родитель 7cc0f0e89c
Коммит 8c14c7f000
2 изменённых файлов: 277 добавлений и 43 удалений

Просмотреть файл

@ -18,6 +18,7 @@
#include "js/Initialization.h"
#include "js/Printf.h"
#include "jsapi.h"
#include "json/json.h"
#include "mozilla/BlocksRingBufferGeckoExtensions.h"
#include "mozilla/UniquePtrExtensions.h"
#include "nsIThread.h"
@ -25,7 +26,7 @@
#include "gtest/gtest.h"
#include <string.h>
#include <cstring>
// Note: profiler_init() has already been called in XRE_main(), so we can't
// test it here. Likewise for profiler_shutdown(), and AutoProfilerInit
@ -580,15 +581,17 @@ TEST(GeckoProfiler, Markers)
profiler_start(PROFILER_DEFAULT_ENTRIES, PROFILER_DEFAULT_INTERVAL, features,
filters, MOZ_ARRAY_LENGTH(filters));
profiler_tracing("A", "B", JS::ProfilingCategoryPair::OTHER, TRACING_EVENT);
PROFILER_TRACING("A", "C", OTHER, TRACING_INTERVAL_START);
PROFILER_TRACING("A", "C", OTHER, TRACING_INTERVAL_END);
profiler_tracing("A", "tracing event", JS::ProfilingCategoryPair::OTHER,
TRACING_EVENT);
PROFILER_TRACING("A", "tracing start", OTHER, TRACING_INTERVAL_START);
PROFILER_TRACING("A", "tracing end", OTHER, TRACING_INTERVAL_END);
UniqueProfilerBacktrace bt = profiler_get_backtrace();
profiler_tracing("B", "A", JS::ProfilingCategoryPair::OTHER, TRACING_EVENT,
profiler_tracing("B", "tracing event with stack",
JS::ProfilingCategoryPair::OTHER, TRACING_EVENT,
std::move(bt));
{ AUTO_PROFILER_TRACING("C", "A", OTHER); }
{ AUTO_PROFILER_TRACING("C", "auto tracing", OTHER); }
PROFILER_ADD_MARKER("M1", OTHER);
PROFILER_ADD_MARKER_WITH_PAYLOAD("M2", OTHER, TracingMarkerPayload,
@ -604,13 +607,13 @@ TEST(GeckoProfiler, Markers)
}
// The GTestMarkerPayloads should have been created, serialized, and
// destroyed.
ASSERT_EQ(GTestMarkerPayload::sNumCreated, 10);
ASSERT_EQ(GTestMarkerPayload::sNumSerialized, 10);
ASSERT_EQ(GTestMarkerPayload::sNumDeserialized, 0);
ASSERT_EQ(GTestMarkerPayload::sNumStreamed, 0);
ASSERT_EQ(GTestMarkerPayload::sNumDestroyed, 10);
EXPECT_EQ(GTestMarkerPayload::sNumCreated, 10);
EXPECT_EQ(GTestMarkerPayload::sNumSerialized, 10);
EXPECT_EQ(GTestMarkerPayload::sNumDeserialized, 0);
EXPECT_EQ(GTestMarkerPayload::sNumStreamed, 0);
EXPECT_EQ(GTestMarkerPayload::sNumDestroyed, 10);
// Create two strings: one that is the maximum allowed length, and one that
// Create three strings: two that are the maximum allowed length, and one that
// is one char longer.
static const size_t kMax = ProfileBuffer::kMaxFrameKeyLength;
UniquePtr<char[]> okstr1 = MakeUnique<char[]>(kMax);
@ -624,8 +627,11 @@ TEST(GeckoProfiler, Markers)
okstr1[kMax - 1] = '\0';
okstr2[kMax - 1] = '\0';
longstr[kMax] = '\0';
// Should be output as-is.
AUTO_PROFILER_LABEL_DYNAMIC_CSTR("", LAYOUT, okstr1.get());
// Should be output as label + space + okstr2.
AUTO_PROFILER_LABEL_DYNAMIC_CSTR("okstr2", LAYOUT, okstr2.get());
// Should be output as "(too long)".
AUTO_PROFILER_LABEL_DYNAMIC_CSTR("", LAYOUT, longstr.get());
// Sleep briefly to ensure a sample is taken and the pending markers are
@ -633,33 +639,255 @@ TEST(GeckoProfiler, Markers)
PR_Sleep(PR_MillisecondsToInterval(500));
SpliceableChunkedJSONWriter w;
ASSERT_TRUE(profiler_stream_json_for_this_process(w));
UniquePtr<char[]> profile = w.WriteFunc()->CopyData();
w.Start();
EXPECT_TRUE(profiler_stream_json_for_this_process(w));
w.End();
// The GTestMarkerPayloads should have been deserialized, streamed, and
// destroyed.
ASSERT_EQ(GTestMarkerPayload::sNumCreated, 10 + 0);
ASSERT_EQ(GTestMarkerPayload::sNumSerialized, 10 + 0);
ASSERT_EQ(GTestMarkerPayload::sNumDeserialized, 0 + 10);
ASSERT_EQ(GTestMarkerPayload::sNumStreamed, 0 + 10);
ASSERT_EQ(GTestMarkerPayload::sNumDestroyed, 10 + 10);
for (int i = 0; i < 10; i++) {
char buf[64];
SprintfLiteral(buf, "\"gtest-%d\"", i);
ASSERT_TRUE(strstr(profile.get(), buf));
EXPECT_EQ(GTestMarkerPayload::sNumCreated, 10 + 0);
EXPECT_EQ(GTestMarkerPayload::sNumSerialized, 10 + 0);
EXPECT_EQ(GTestMarkerPayload::sNumDeserialized, 0 + 10);
EXPECT_EQ(GTestMarkerPayload::sNumStreamed, 0 + 10);
EXPECT_EQ(GTestMarkerPayload::sNumDestroyed, 10 + 10);
UniquePtr<char[]> profile = w.WriteFunc()->CopyData();
ASSERT_TRUE(!!profile.get());
// Expected markers, in order.
enum State {
S_tracing_event,
S_tracing_start,
S_tracing_end,
S_tracing_event_with_stack,
S_tracing_auto_tracing_start,
S_tracing_auto_tracing_end,
S_M1,
S_tracing_M2_C,
S_M3,
S_tracing_M4_C_stack,
S_M5_gtest0,
S_M5_gtest1,
S_M5_gtest2,
S_M5_gtest3,
S_M5_gtest4,
S_M5_gtest5,
S_M5_gtest6,
S_M5_gtest7,
S_M5_gtest8,
S_M5_gtest9,
S_LAST,
} state = State(0);
// Extract JSON.
Json::Value parsedRoot;
Json::CharReaderBuilder builder;
const std::unique_ptr<Json::CharReader> reader(builder.newCharReader());
ASSERT_TRUE(reader->parse(profile.get(), strchr(profile.get(), '\0'),
&parsedRoot, nullptr));
// Use const root, we only want to test what's in the profile, not change it.
const Json::Value& root = parsedRoot;
ASSERT_TRUE(root.isObject());
// We have a root object.
// Most common test: Checks that the given value is present, is of the
// expected type, and has the expected value.
#define EXPECT_EQ_JSON(GETTER, TYPE, VALUE) \
if ((GETTER).isNull()) { \
EXPECT_FALSE((GETTER).isNull()); \
} else if (!(GETTER).is##TYPE()) { \
EXPECT_TRUE((GETTER).is##TYPE()); \
} else { \
EXPECT_EQ((GETTER).as##TYPE(), (VALUE)); \
}
// okstr1 should appear as is.
ASSERT_TRUE(strstr(profile.get(), okstr1.get()));
{
const Json::Value& threads = root["threads"];
ASSERT_TRUE(!threads.isNull());
ASSERT_TRUE(threads.isArray());
ASSERT_EQ(threads.size(), 1u);
// okstr2 should appear, slightly truncated with "okstr2 " in front of it.
// (Nb: this only checks the front part of the marker string.)
ASSERT_TRUE(strstr(profile.get(), "okstr2 bbbbbbbbb"));
// root.threads is a 1-element array.
// longstr should be replaced with "(too long)".
ASSERT_TRUE(!strstr(profile.get(), longstr.get()));
ASSERT_TRUE(strstr(profile.get(), "(too long)"));
{
const Json::Value& thread0 = threads[0];
ASSERT_TRUE(thread0.isObject());
// root.threads[0] is an object.
// Keep a reference to the string table in this block, it will be used
// below.
const Json::Value& stringTable = thread0["stringTable"];
ASSERT_TRUE(stringTable.isArray());
// Test the expected labels in the string table.
bool foundOkstr1 = false;
bool foundOkstr2 = false;
const std::string okstr2Label = std::string("okstr2 ") + okstr2.get();
bool foundTooLong = false;
for (const auto& s : stringTable) {
ASSERT_TRUE(s.isString());
std::string sString = s.asString();
if (sString == okstr1.get()) {
EXPECT_FALSE(foundOkstr1);
foundOkstr1 = true;
} else if (sString == okstr2Label) {
EXPECT_FALSE(foundOkstr2);
foundOkstr2 = true;
} else if (sString == "(too long)") {
EXPECT_FALSE(foundTooLong);
foundTooLong = true;
} else {
EXPECT_NE(sString, longstr.get());
}
}
EXPECT_TRUE(foundOkstr1);
EXPECT_TRUE(foundOkstr2);
EXPECT_TRUE(foundTooLong);
{
const Json::Value& markers = thread0["markers"];
ASSERT_TRUE(markers.isObject());
// root.threads[0].markers is an object.
{
const Json::Value& data = markers["data"];
ASSERT_TRUE(data.isArray());
// root.threads[0].markers.data is an array.
for (const Json::Value& marker : data) {
ASSERT_TRUE(marker.isArray());
ASSERT_GE(marker.size(), 3u);
ASSERT_LE(marker.size(), 4u);
// root.threads[0].markers.data[i] is an array with 3 or 4 elements.
ASSERT_TRUE(marker[0].isUInt()); // name id
const Json::Value& name = stringTable[marker[0].asUInt()];
ASSERT_TRUE(name.isString());
std::string nameString = name.asString();
EXPECT_TRUE(marker[1].isNumeric()); // timestamp
EXPECT_TRUE(marker[2].isUInt()); // category
if (marker.size() == 3u) {
// root.threads[0].markers.data[i] is an array with 3 elements,
// so there is no payload.
if (nameString == "M1") {
ASSERT_EQ(state, S_M1);
state = State(state + 1);
} else if (nameString == "M3") {
ASSERT_EQ(state, S_M3);
state = State(state + 1);
}
} else {
// root.threads[0].markers.data[i] is an array with 4 elements,
// so there is a payload.
const Json::Value& payload = marker[3];
ASSERT_TRUE(payload.isObject());
// root.threads[0].markers.data[i][3] is an object (payload).
// It should at least have a "type" string.
const Json::Value& type = payload["type"];
ASSERT_TRUE(type.isString());
std::string typeString = type.asString();
if (nameString == "tracing event") {
EXPECT_EQ(state, S_tracing_event);
state = State(S_tracing_event + 1);
EXPECT_EQ(typeString, "tracing");
EXPECT_EQ_JSON(payload["category"], String, "A");
EXPECT_TRUE(payload["interval"].isNull());
EXPECT_TRUE(payload["stack"].isNull());
} else if (nameString == "tracing start") {
EXPECT_EQ(state, S_tracing_start);
state = State(S_tracing_start + 1);
EXPECT_EQ(typeString, "tracing");
EXPECT_EQ_JSON(payload["category"], String, "A");
EXPECT_EQ_JSON(payload["interval"], String, "start");
EXPECT_TRUE(payload["stack"].isNull());
} else if (nameString == "tracing end") {
EXPECT_EQ(state, S_tracing_end);
state = State(S_tracing_end + 1);
EXPECT_EQ(typeString, "tracing");
EXPECT_EQ_JSON(payload["category"], String, "A");
EXPECT_EQ_JSON(payload["interval"], String, "end");
EXPECT_TRUE(payload["stack"].isNull());
} else if (nameString == "tracing event with stack") {
EXPECT_EQ(state, S_tracing_event_with_stack);
state = State(S_tracing_event_with_stack + 1);
EXPECT_EQ(typeString, "tracing");
EXPECT_EQ_JSON(payload["category"], String, "B");
EXPECT_TRUE(payload["interval"].isNull());
EXPECT_TRUE(payload["stack"].isObject());
} else if (nameString == "auto tracing") {
switch (state) {
case S_tracing_auto_tracing_start:
state = State(S_tracing_auto_tracing_start + 1);
EXPECT_EQ_JSON(payload["category"], String, "C");
EXPECT_EQ_JSON(payload["interval"], String, "start");
EXPECT_TRUE(payload["stack"].isNull());
break;
case S_tracing_auto_tracing_end:
state = State(S_tracing_auto_tracing_end + 1);
EXPECT_EQ_JSON(payload["category"], String, "C");
EXPECT_EQ_JSON(payload["interval"], String, "end");
ASSERT_TRUE(payload["stack"].isNull());
break;
default:
EXPECT_TRUE(state == S_tracing_auto_tracing_start ||
state == S_tracing_auto_tracing_end);
break;
}
} else if (nameString == "M2") {
EXPECT_EQ(state, S_tracing_M2_C);
state = State(S_tracing_M2_C + 1);
EXPECT_EQ(typeString, "tracing");
EXPECT_EQ_JSON(payload["category"], String, "C");
EXPECT_TRUE(payload["interval"].isNull());
EXPECT_TRUE(payload["stack"].isNull());
} else if (nameString == "M4") {
EXPECT_EQ(state, S_tracing_M4_C_stack);
state = State(S_tracing_M4_C_stack + 1);
EXPECT_EQ(typeString, "tracing");
EXPECT_EQ_JSON(payload["category"], String, "C");
EXPECT_TRUE(payload["interval"].isNull());
EXPECT_TRUE(payload["stack"].isObject());
} else if (nameString == "M5") {
EXPECT_EQ(typeString, "gtest");
// It should only have one more element (apart from "type").
ASSERT_EQ(payload.size(), 2u);
const auto itEnd = payload.end();
for (auto it = payload.begin(); it != itEnd; ++it) {
std::string key = it.name();
if (key != "type") {
const Json::Value& value = *it;
ASSERT_TRUE(value.isInt());
int valueInt = value.asInt();
// We expect `"gtest-<i>" : <i>`.
EXPECT_EQ(state, State(S_M5_gtest0 + valueInt));
state = State(state + 1);
EXPECT_EQ(key,
std::string("gtest-") + std::to_string(valueInt));
}
}
}
} // marker with payload
} // for (marker:data)
} // markers.data
} // markers
} // thread0
} // threads
// We should have read all expected markers.
EXPECT_EQ(state, S_LAST);
Maybe<ProfilerBufferInfo> info = profiler_get_buffer_info();
MOZ_RELEASE_ASSERT(info.isSome());
@ -693,12 +921,13 @@ TEST(GeckoProfiler, Markers)
profiler_stop();
// Nothing more should have happened to the GTestMarkerPayloads.
ASSERT_EQ(GTestMarkerPayload::sNumCreated, 10 + 0 + 0);
ASSERT_EQ(GTestMarkerPayload::sNumSerialized, 10 + 0 + 0);
ASSERT_EQ(GTestMarkerPayload::sNumDeserialized, 0 + 10 + 0);
ASSERT_EQ(GTestMarkerPayload::sNumStreamed, 0 + 10 + 0);
ASSERT_EQ(GTestMarkerPayload::sNumDestroyed, 10 + 10 + 0);
EXPECT_EQ(GTestMarkerPayload::sNumCreated, 10 + 0 + 0);
EXPECT_EQ(GTestMarkerPayload::sNumSerialized, 10 + 0 + 0);
EXPECT_EQ(GTestMarkerPayload::sNumDeserialized, 0 + 10 + 0);
EXPECT_EQ(GTestMarkerPayload::sNumStreamed, 0 + 10 + 0);
EXPECT_EQ(GTestMarkerPayload::sNumDestroyed, 10 + 10 + 0);
// Try to add markers while the profiler is stopped.
for (int i = 0; i < 10; i++) {
PROFILER_ADD_MARKER_WITH_PAYLOAD("M5", OTHER, GTestMarkerPayload, (i));
}
@ -707,17 +936,17 @@ TEST(GeckoProfiler, Markers)
profiler_start(PROFILER_DEFAULT_ENTRIES, PROFILER_DEFAULT_INTERVAL, features,
filters, MOZ_ARRAY_LENGTH(filters));
ASSERT_TRUE(profiler_stream_json_for_this_process(w));
EXPECT_TRUE(profiler_stream_json_for_this_process(w));
profiler_stop();
// The second set of GTestMarkerPayloads should not have been serialized or
// streamed.
ASSERT_EQ(GTestMarkerPayload::sNumCreated, 10 + 0 + 0 + 10);
ASSERT_EQ(GTestMarkerPayload::sNumSerialized, 10 + 0 + 0 + 0);
ASSERT_EQ(GTestMarkerPayload::sNumDeserialized, 0 + 10 + 0 + 0);
ASSERT_EQ(GTestMarkerPayload::sNumStreamed, 0 + 10 + 0 + 0);
ASSERT_EQ(GTestMarkerPayload::sNumDestroyed, 10 + 10 + 0 + 10);
EXPECT_EQ(GTestMarkerPayload::sNumCreated, 10 + 0 + 0 + 10);
EXPECT_EQ(GTestMarkerPayload::sNumSerialized, 10 + 0 + 0 + 0);
EXPECT_EQ(GTestMarkerPayload::sNumDeserialized, 0 + 10 + 0 + 0);
EXPECT_EQ(GTestMarkerPayload::sNumStreamed, 0 + 10 + 0 + 0);
EXPECT_EQ(GTestMarkerPayload::sNumDestroyed, 10 + 10 + 0 + 10);
}
TEST(GeckoProfiler, DurationLimit)

Просмотреть файл

@ -13,6 +13,7 @@ if (CONFIG['OS_TARGET'] in ('Android', 'Linux') and
]
LOCAL_INCLUDES += [
'/toolkit/components/jsoncpp/include',
'/tools/profiler/core',
'/tools/profiler/gecko',
'/tools/profiler/lul',
@ -24,6 +25,10 @@ if CONFIG['OS_TARGET'] != 'Android':
'ThreadProfileTest.cpp',
]
USE_LIBS += [
'jsoncpp',
]
FINAL_LIBRARY = 'xul-gtest'
if CONFIG['CC_TYPE'] in ('clang', 'gcc'):