Index: clangd/ClangdUnit.cpp =================================================================== --- clangd/ClangdUnit.cpp +++ clangd/ClangdUnit.cpp @@ -1293,7 +1293,8 @@ // (if there are no other references to it). OldPreamble.reset(); - trace::Span Tracer(llvm::Twine("Preamble: ") + That->FileName); + trace::Span Tracer("Preamble"); + SPAN_ATTACH(Tracer, "File", That->FileName); std::vector PreambleDiags; StoreDiagsConsumer PreambleDiagnosticsConsumer(/*ref*/ PreambleDiags); IntrusiveRefCntPtr PreambleDiagsEngine = @@ -1342,7 +1343,8 @@ // Compute updated AST. llvm::Optional NewAST; { - trace::Span Tracer(llvm::Twine("Build: ") + That->FileName); + trace::Span Tracer("Build"); + SPAN_ATTACH(Tracer, "File", That->FileName); NewAST = ParsedAST::Build( std::move(CI), PreambleForAST, SerializedPreambleDecls, std::move(ContentsBuffer), PCHs, VFS, That->Logger); Index: clangd/JSONExpr.h =================================================================== --- clangd/JSONExpr.h +++ clangd/JSONExpr.h @@ -55,14 +55,14 @@ // object (json::obj) // // The kind can be queried directly, or implicitly via the typed accessors: -// if (Optional S = E.string()) +// if (Optional S = E.asString() // assert(E.kind() == Expr::String); // // Array and Object also have typed indexing accessors for easy traversal: // Expected E = parse(R"( {"options": {"font": "sans-serif"}} )"); -// if (json::obj* O = E->object()) -// if (json::obj* Opts = O->object("options")) -// if (Optional Font = Opts->string("font")) +// if (json::obj* O = E->asObject()) +// if (json::obj* Opts = O->getObject("options")) +// if (Optional Font = Opts->getString("font")) // assert(Opts->at("font").kind() == Expr::String); // // === Serialization === @@ -166,38 +166,38 @@ } // Typed accessors return None/nullptr if the Expr is not of this type. - llvm::Optional null() const { + llvm::Optional asNull() const { if (LLVM_LIKELY(Type == T_Null)) return nullptr; return llvm::None; } - llvm::Optional boolean() const { - if (LLVM_LIKELY(Type == T_Null)) + llvm::Optional asBoolean() const { + if (LLVM_LIKELY(Type == T_Boolean)) return as(); return llvm::None; } - llvm::Optional number() const { + llvm::Optional asNumber() const { if (LLVM_LIKELY(Type == T_Number)) return as(); return llvm::None; } - llvm::Optional string() const { + llvm::Optional asString() const { if (Type == T_String) return llvm::StringRef(as()); if (LLVM_LIKELY(Type == T_StringRef)) return as(); return llvm::None; } - const ObjectExpr *object() const { + const ObjectExpr *asObject() const { return LLVM_LIKELY(Type == T_Object) ? &as() : nullptr; } - ObjectExpr *object() { + ObjectExpr *asObject() { return LLVM_LIKELY(Type == T_Object) ? &as() : nullptr; } - const ArrayExpr *array() const { + const ArrayExpr *asArray() const { return LLVM_LIKELY(Type == T_Array) ? &as() : nullptr; } - ArrayExpr *array() { + ArrayExpr *asArray() { return LLVM_LIKELY(Type == T_Array) ? &as() : nullptr; } @@ -292,6 +292,63 @@ Expr &operator[](ObjectKey &&K) { return emplace(std::move(K), Expr(nullptr)).first->second; } + + // Look up a property, returning nullptr if it doesn't exist. + json::Expr *get(const ObjectKey &K) { + auto I = find(K); + if (I == end()) + return nullptr; + return &I->second; + } + const json::Expr *get(const ObjectKey &K) const { + auto I = find(K); + if (I == end()) + return nullptr; + return &I->second; + } + // Typed accessors return None/nullptr if + // - the property doesn't exist + // - or it has the wrong type + llvm::Optional getNull(const ObjectKey &K) const { + if (auto *V = get(K)) + return V->asNull(); + return llvm::None; + } + llvm::Optional getBoolean(const ObjectKey &K) const { + if (auto *V = get(K)) + return V->asBoolean(); + return llvm::None; + } + llvm::Optional getNumber(const ObjectKey &K) const { + if (auto *V = get(K)) + return V->asNumber(); + return llvm::None; + } + llvm::Optional getString(const ObjectKey &K) const { + if (auto *V = get(K)) + return V->asString(); + return llvm::None; + } + const ObjectExpr *getObject(const ObjectKey &K) const { + if (auto *V = get(K)) + return V->asObject(); + return nullptr; + } + ObjectExpr *getObject(const ObjectKey &K) { + if (auto *V = get(K)) + return V->asObject(); + return nullptr; + } + const ArrayExpr *getArray(const ObjectKey &K) const { + if (auto *V = get(K)) + return V->asArray(); + return nullptr; + } + ArrayExpr *getArray(const ObjectKey &K) { + if (auto *V = get(K)) + return V->asArray(); + return nullptr; + } }; class ArrayExpr : public std::vector { @@ -306,6 +363,26 @@ for (const auto &V : C) emplace_back(V); } + + // Typed accessors return None/nullptr if the element has the wrong type. + llvm::Optional getNull(size_t I) const { + return (*this)[I].asNull(); + } + llvm::Optional getBoolean(size_t I) const { + return (*this)[I].asBoolean(); + } + llvm::Optional getNumber(size_t I) const { + return (*this)[I].asNumber(); + } + llvm::Optional getString(size_t I) const { + return (*this)[I].asString(); + } + const ObjectExpr *getObject(size_t I) const { + return (*this)[I].asObject(); + } + ObjectExpr *getObject(size_t I) { return (*this)[I].asObject(); } + const ArrayExpr *getArray(size_t I) const { return (*this)[I].asArray(); } + ArrayExpr *getArray(size_t I) { return (*this)[I].asArray(); } }; private: Index: clangd/JSONExpr.cpp =================================================================== --- clangd/JSONExpr.cpp +++ clangd/JSONExpr.cpp @@ -161,7 +161,7 @@ } case '[': { Out = json::ary{}; - json::ary &A = *Out.array(); + json::ary &A = *Out.asArray(); eatWhitespace(); if (peek() == ']') { ++P; @@ -185,7 +185,7 @@ } case '{': { Out = json::obj{}; - json::obj &O = *Out.object(); + json::obj &O = *Out.asObject(); eatWhitespace(); if (peek() == '}') { ++P; @@ -507,17 +507,17 @@ return false; switch (L.kind()) { case Expr::Null: - return L.null() == R.null(); + return *L.asNull() == *R.asNull(); case Expr::Boolean: - return L.boolean() == R.boolean(); + return *L.asBoolean() == *R.asBoolean(); case Expr::Number: - return L.boolean() == R.boolean(); + return *L.asNumber() == *R.asNumber(); case Expr::String: - return L.string() == R.string(); + return *L.asString() == *R.asString(); case Expr::Array: - return *L.array() == *R.array(); + return *L.asArray() == *R.asArray(); case Expr::Object: - return *L.object() == *R.object(); + return *L.asObject() == *R.asObject(); } llvm_unreachable("Unknown expression kind"); } Index: clangd/JSONRPCDispatcher.h =================================================================== --- clangd/JSONRPCDispatcher.h +++ clangd/JSONRPCDispatcher.h @@ -13,6 +13,7 @@ #include "JSONExpr.h" #include "Logger.h" #include "Protocol.h" +#include "Trace.h" #include "clang/Basic/LLVM.h" #include "llvm/ADT/SmallString.h" #include "llvm/ADT/StringMap.h" @@ -55,8 +56,13 @@ /// Context object passed to handlers to allow replies. class RequestContext { public: - RequestContext(JSONOutput &Out, llvm::Optional ID) - : Out(Out), ID(std::move(ID)) {} + RequestContext(JSONOutput &Out, StringRef Method, + llvm::Optional ID) + : Out(Out), ID(std::move(ID)), + Tracer(llvm::make_unique(Method)) { + if (this->ID) + SPAN_ATTACH(tracer(), "ID", *this->ID); + } /// Sends a successful reply. void reply(json::Expr &&Result); @@ -65,9 +71,12 @@ /// Sends a request to the client. void call(llvm::StringRef Method, json::Expr &&Params); + trace::Span &tracer() { return *Tracer; } + private: JSONOutput &Out; llvm::Optional ID; + std::unique_ptr Tracer; }; /// Main JSONRPC entry point. This parses the JSONRPC "header" and calls the Index: clangd/JSONRPCDispatcher.cpp =================================================================== --- clangd/JSONRPCDispatcher.cpp +++ clangd/JSONRPCDispatcher.cpp @@ -59,6 +59,7 @@ Out.log("Attempted to reply to a notification!\n"); return; } + SPAN_ATTACH(tracer(), "Reply", Result); Out.writeMessage(json::obj{ {"jsonrpc", "2.0"}, {"id", *ID}, @@ -69,6 +70,9 @@ void RequestContext::replyError(ErrorCode code, const llvm::StringRef &Message) { Out.log("Error " + Twine(static_cast(code)) + ": " + Message + "\n"); + SPAN_ATTACH(tracer(), "Error", + (json::obj{{"code", static_cast(code)}, + {"message", Message.str()}})); if (ID) { Out.writeMessage(json::obj{ {"jsonrpc", "2.0"}, @@ -82,6 +86,8 @@ void RequestContext::call(StringRef Method, json::Expr &&Params) { // FIXME: Generate/Increment IDs for every request so that we can get proper // replies once we need to. + SPAN_ATTACH(tracer(), "Call", + (json::obj{{"method", Method.str()}, {"params", Params}})); Out.writeMessage(json::obj{ {"jsonrpc", "2.0"}, {"id", 1}, @@ -104,8 +110,7 @@ llvm::StringRef MethodStr = Method->getValue(MethodStorage); auto I = Handlers.find(MethodStr); auto &Handler = I != Handlers.end() ? I->second : UnknownHandler; - trace::Span Tracer(MethodStr); - Handler(RequestContext(Out, std::move(ID)), Params); + Handler(RequestContext(Out, MethodStr, std::move(ID)), Params); } bool JSONRPCDispatcher::call(StringRef Content, JSONOutput &Out) const { @@ -249,7 +254,6 @@ std::vector JSON(ContentLength + 1, '\0'); llvm::StringRef JSONRef; { - trace::Span Tracer("Reading request"); // Now read the JSON. Insert a trailing null byte as required by the // YAML parser. In.read(JSON.data(), ContentLength); Index: clangd/Trace.h =================================================================== --- clangd/Trace.h +++ clangd/Trace.h @@ -21,6 +21,7 @@ #ifndef LLVM_CLANG_TOOLS_EXTRA_CLANGD_TRACE_H_ #define LLVM_CLANG_TOOLS_EXTRA_CLANGD_TRACE_H_ +#include "JSONExpr.h" #include "llvm/ADT/Twine.h" #include "llvm/Support/raw_ostream.h" @@ -35,7 +36,8 @@ class Session { public: // Starts a sessions capturing trace events and writing Trace Event JSON. - static std::unique_ptr create(llvm::raw_ostream &OS); + static std::unique_ptr create(llvm::raw_ostream &OS, + bool Pretty = false); ~Session(); private: @@ -46,14 +48,30 @@ void log(const llvm::Twine &Name); // Records an event whose duration is the lifetime of the Span object. +// +// Arbitrary JSON metadata can be attached while this span is active: +// SPAN_ATTACH(MySpan, "Payload", SomeJSONExpr); +// SomeJSONExpr is evaluated and copied only if actually needed. class Span { public: - Span(const llvm::Twine &Name); + Span(std::string Name); ~Span(); + // Returns mutable span metadata if this span is interested. + // Prefer to use SPAN_ATTACH rather than accessing this directly. + json::obj *args() { return Args.get(); } + private: + std::unique_ptr Args; }; +#define SPAN_ATTACH(S, Name, Expr) \ + do { \ + if ((S).args() != nullptr) { \ + (*((S).args()))[(Name)] = (Expr); \ + } \ + } while (0) + } // namespace trace } // namespace clangd } // namespace clang Index: clangd/Trace.cpp =================================================================== --- clangd/Trace.cpp +++ clangd/Trace.cpp @@ -27,13 +27,17 @@ // Perhaps we should replace this by something that disturbs performance less. class Tracer { public: - Tracer(raw_ostream &Out) - : Out(Out), Sep(""), Start(std::chrono::system_clock::now()) { + Tracer(raw_ostream &Out, bool Pretty) + : Out(Out), Sep(""), Start(std::chrono::system_clock::now()), + JSONFormat(Pretty ? "{0:2}" : "{0}") { // The displayTimeUnit must be ns to avoid low-precision overlap // calculations! Out << R"({"displayTimeUnit":"ns","traceEvents":[)" << "\n"; - rawEvent("M", R"("name": "process_name", "args":{"name":"clangd"})"); + rawEvent("M", json::obj{ + {"name", "process_name"}, + {"args", json::obj{{"name", "clangd"}}}, + }); } ~Tracer() { @@ -43,7 +47,7 @@ // Record an event on the current thread. ph, pid, tid, ts are set. // Contents must be a list of the other JSON key/values. - template void event(StringRef Phase, const T &Contents) { + void event(StringRef Phase, json::obj &&Contents) { uint64_t TID = get_threadid(); std::lock_guard Lock(Mu); // If we haven't already, emit metadata describing this thread. @@ -51,24 +55,26 @@ SmallString<32> Name; get_thread_name(Name); if (!Name.empty()) { - rawEvent( - "M", - formatv( - R"("tid": {0}, "name": "thread_name", "args":{"name":"{1}"})", - TID, StringRef(&Name[0], Name.size()))); + rawEvent("M", json::obj{ + {"tid", TID}, + {"name", "thread_name"}, + {"args", json::obj{{"name", Name}}}, + }); } } - rawEvent(Phase, formatv(R"("ts":{0}, "tid":{1}, {2})", timestamp(), TID, - Contents)); + Contents["ts"] = timestamp(); + Contents["tid"] = TID; + rawEvent(Phase, std::move(Contents)); } private: // Record an event. ph and pid are set. // Contents must be a list of the other JSON key/values. - template - void rawEvent(StringRef Phase, const T &Contents) /*REQUIRES(Mu)*/ { + void rawEvent(StringRef Phase, json::obj &&Event) /*REQUIRES(Mu)*/ { // PID 0 represents the clangd process. - Out << Sep << R"({"pid":0, "ph":")" << Phase << "\", " << Contents << "}"; + Event["pid"] = 0; + Event["ph"] = Phase; + Out << Sep << formatv(JSONFormat, json::Expr(std::move(Event))); Sep = ",\n"; } @@ -82,14 +88,15 @@ const char *Sep /*GUARDED_BY(Mu)*/; DenseSet ThreadsWithMD /*GUARDED_BY(Mu)*/; const sys::TimePoint<> Start; + const char *JSONFormat; }; static Tracer *T = nullptr; } // namespace -std::unique_ptr Session::create(raw_ostream &OS) { +std::unique_ptr Session::create(raw_ostream &OS, bool Pretty) { assert(!T && "A session is already active"); - T = new Tracer(OS); + T = new Tracer(OS, Pretty); return std::unique_ptr(new Session()); } @@ -101,19 +108,25 @@ void log(const Twine &Message) { if (!T) return; - T->event("i", formatv(R"("name":"{0}")", yaml::escape(Message.str()))); + T->event("i", json::obj{ + {"name", "Log"}, + {"args", json::obj{{"Message", Message.str()}}}, + }); } -Span::Span(const Twine &Text) { +Span::Span(std::string Name) { if (!T) return; - T->event("B", formatv(R"("name":"{0}")", yaml::escape(Text.str()))); + T->event("B", json::obj{{"name", std::move(Name)}}); + Args = llvm::make_unique(); } Span::~Span() { if (!T) return; - T->event("E", R"("_":0)" /* Dummy property to ensure valid JSON */); + if (!Args) + Args = llvm::make_unique(); + T->event("E", Args ? json::obj{{"args", std::move(*Args)}} : json::obj{}); } } // namespace trace Index: clangd/tool/ClangdMain.cpp =================================================================== --- clangd/tool/ClangdMain.cpp +++ clangd/tool/ClangdMain.cpp @@ -124,7 +124,7 @@ TraceFile.reset(); llvm::errs() << "Error while opening trace file: " << EC.message(); } else { - TraceSession = trace::Session::create(*TraceStream); + TraceSession = trace::Session::create(*TraceStream, PrettyPrint); } } Index: test/clangd/trace.test =================================================================== --- test/clangd/trace.test +++ test/clangd/trace.test @@ -1,4 +1,4 @@ -# RUN: clangd -run-synchronously -trace %t < %s && FileCheck %s < %t +# RUN: clangd -pretty -run-synchronously -trace %t < %s && FileCheck %s < %t # It is absolutely vital that this file has CRLF line endings. # Content-Length: 125 @@ -8,9 +8,19 @@ Content-Length: 152 {"jsonrpc":"2.0","method":"textDocument/didOpen","params":{"textDocument":{"uri":"file:///foo.c","languageId":"c","version":1,"text":"void main() {}"}}} -# CHECK: "textDocument/didOpen" -# CHECK: "Preamble: /foo.c" -# CHECK: "Build: /foo.c" +# CHECK: {"displayTimeUnit":"ns","traceEvents":[ +# Start opening the doc. +# CHECK: "name": "textDocument/didOpen" +# CHECK: "ph": "E" +# Start building the preamble. +# CHECK: "name": "Preamble" +# CHECK: }, +# Finish building the preamble, with filename. +# CHECK: "File": "/foo.c" +# CHECK-NEXT: }, +# CHECK-NEXT: "ph": "E" +# Start building the file. +# CHECK: "name": "Build" Content-Length: 44 {"jsonrpc":"2.0","id":5,"method":"shutdown"} Index: unittests/clangd/JSONExprTests.cpp =================================================================== --- unittests/clangd/JSONExprTests.cpp +++ unittests/clangd/JSONExprTests.cpp @@ -167,7 +167,6 @@ ExpectErr("Unexpected EOF", ""); ExpectErr("Unexpected EOF", "["); ExpectErr("Text after end of document", "[][]"); - ExpectErr("Text after end of document", "[][]"); ExpectErr("Invalid bareword", "fuzzy"); ExpectErr("Expected , or ]", "[2?]"); ExpectErr("Expected object key", "{a:2}"); @@ -185,6 +184,49 @@ })"); } +TEST(JSONTest, Inspection) { + llvm::Expected Doc = parse(R"( + { + "null": null, + "boolean": false, + "number": 2.78, + "string": "json", + "array": [null, true, 3.14, "hello", [1,2,3], {"time": "arrow"}], + "object": {"fruit": "banana"} + } + )"); + EXPECT_TRUE(!!Doc); + + obj *O = Doc->asObject(); + ASSERT_TRUE(O); + + EXPECT_FALSE(O->getNull("missing")); + EXPECT_FALSE(O->getNull("boolean")); + EXPECT_TRUE(O->getNull("null")); + + EXPECT_EQ(O->getNumber("number"), llvm::Optional(2.78)); + EXPECT_EQ(O->getString("string"), llvm::Optional("json")); + ASSERT_FALSE(O->getObject("missing")); + ASSERT_FALSE(O->getObject("array")); + ASSERT_TRUE(O->getObject("object")); + EXPECT_EQ(*O->getObject("object"), (obj{{"fruit", "banana"}})); + + ary *A = O->getArray("array"); + ASSERT_TRUE(A); + EXPECT_EQ(A->getBoolean(1), llvm::Optional(true)); + ASSERT_TRUE(A->getArray(4)); + EXPECT_EQ(*A->getArray(4), (ary{1, 2, 3})); + int I = 0; + for (Expr &E : *A) { + if (I++ == 5) { + ASSERT_TRUE(E.asObject()); + EXPECT_EQ(E.asObject()->getString("time"), + llvm::Optional("arrow")); + } else + EXPECT_FALSE(E.asObject()); + } +} + } // namespace } // namespace json } // namespace clangd Index: unittests/clangd/TraceTests.cpp =================================================================== --- unittests/clangd/TraceTests.cpp +++ unittests/clangd/TraceTests.cpp @@ -116,7 +116,7 @@ ASSERT_NE(++Event, Events->end()) << "Expected span start"; EXPECT_TRUE(VerifyObject(*Event, {{"ph", "B"}, {"name", "A"}})); ASSERT_NE(++Event, Events->end()) << "Expected log message"; - EXPECT_TRUE(VerifyObject(*Event, {{"ph", "i"}, {"name", "B"}})); + EXPECT_TRUE(VerifyObject(*Event, {{"ph", "i"}, {"name", "Log"}})); ASSERT_NE(++Event, Events->end()) << "Expected span end"; EXPECT_TRUE(VerifyObject(*Event, {{"ph", "E"}})); ASSERT_EQ(++Event, Events->end());