Remove Timer and PerformanceImportFile

This commit is contained in:
Fangrui Song 2018-05-31 21:21:34 -07:00
parent 34dc1e93e9
commit f0559bba54
19 changed files with 40 additions and 250 deletions

View File

@ -216,7 +216,6 @@ target_sources(ccls PRIVATE
src/serializer.cc
src/test.cc
src/third_party_impl.cc
src/timer.cc
src/type_printer.cc
src/utils.cc
src/working_files.cc)

View File

@ -4,7 +4,6 @@
#include "filesystem.hh"
#include "log.hh"
#include "platform.h"
#include "timer.h"
#include <llvm/ADT/Twine.h>
#include <llvm/Support/Threading.h>
@ -454,21 +453,17 @@ void CompletionQueryMain(ClangCompleteManager* completion_manager) {
true /*create_if_needed*/);
std::lock_guard<std::mutex> lock(session->completion.lock);
Timer timer;
TryEnsureDocumentParsed(completion_manager, session, &session->completion.tu,
&session->completion.index, false);
timer.ResetAndPrint("[complete] TryEnsureDocumentParsed");
// It is possible we failed to create the document despite
// |TryEnsureDocumentParsed|.
if (!session->completion.tu)
continue;
timer.Reset();
WorkingFiles::Snapshot snapshot =
completion_manager->working_files_->AsSnapshot({StripFileType(path)});
std::vector<CXUnsavedFile> unsaved = snapshot.AsUnsavedFiles();
timer.ResetAndPrint("[complete] Creating WorkingFile snapshot");
unsigned const kCompleteOptions =
CXCodeComplete_IncludeMacros | CXCodeComplete_IncludeBriefComments;
@ -476,7 +471,6 @@ void CompletionQueryMain(ClangCompleteManager* completion_manager) {
session->completion.tu->cx_tu, session->file.filename.c_str(),
request->position.line + 1, request->position.character + 1,
unsaved.data(), (unsigned)unsaved.size(), kCompleteOptions);
timer.ResetAndPrint("[complete] clangCodeCompleteAt");
if (!cx_results) {
request->on_complete({}, false /*is_cached_result*/);
continue;
@ -487,7 +481,6 @@ void CompletionQueryMain(ClangCompleteManager* completion_manager) {
// parameters, as they may be expanded into multiple items
ls_result.reserve(cx_results->NumResults);
timer.Reset();
for (unsigned i = 0; i < cx_results->NumResults; ++i) {
CXCompletionResult& result = cx_results->Results[i];
@ -552,10 +545,6 @@ void CompletionQueryMain(ClangCompleteManager* completion_manager) {
}
}
timer.ResetAndPrint("[complete] Building " +
std::to_string(ls_result.size()) +
" completion results");
request->on_complete(ls_result, false /*is_cached_result*/);
// Make sure |ls_results| is destroyed before clearing |cx_results|.
@ -578,28 +567,22 @@ void DiagnosticQueryMain(ClangCompleteManager* completion_manager) {
// At this point, we must have a translation unit. Block until we have one.
std::lock_guard<std::mutex> lock(session->diagnostics.lock);
Timer timer;
TryEnsureDocumentParsed(
completion_manager, session, &session->diagnostics.tu,
&session->diagnostics.index, false /*emit_diagnostics*/);
timer.ResetAndPrint("[diagnostics] TryEnsureDocumentParsed");
// It is possible we failed to create the document despite
// |TryEnsureDocumentParsed|.
if (!session->diagnostics.tu)
continue;
timer.Reset();
WorkingFiles::Snapshot snapshot =
completion_manager->working_files_->AsSnapshot({StripFileType(path)});
std::vector<CXUnsavedFile> unsaved = snapshot.AsUnsavedFiles();
timer.ResetAndPrint("[diagnostics] Creating WorkingFile snapshot");
// Emit diagnostics.
timer.Reset();
session->diagnostics.tu = ClangTranslationUnit::Reparse(
std::move(session->diagnostics.tu), unsaved);
timer.ResetAndPrint("[diagnostics] clang_reparseTranslationUnit");
if (!session->diagnostics.tu) {
LOG_S(ERROR) << "Reparsing translation unit for diagnostics failed for "
<< path;

View File

@ -78,30 +78,3 @@ struct FileConsumer {
std::string parse_file_;
int thread_id_;
};
// Contains timing information for the entire pipeline for importing a file
// into the querydb.
struct PerformanceImportFile {
// All units are in microseconds.
// [indexer] clang parsing the file
uint64_t index_parse = 0;
// [indexer] build the IndexFile object from clang parse
uint64_t index_build = 0;
// [indexer] save the IndexFile to disk
uint64_t index_save_to_disk = 0;
// [indexer] loading previously cached index
uint64_t index_load_cached = 0;
// [indexer] create delta IndexUpdate object
uint64_t index_make_delta = 0;
// [querydb] update WorkingFile indexed file state
// uint64_t querydb_update_working_file = 0;
// [querydb] apply IndexUpdate
// uint64_t querydb_apply_index_update = 0;
};
MAKE_REFLECT_STRUCT(PerformanceImportFile,
index_parse,
index_build,
index_save_to_disk,
index_load_cached,
index_make_delta);

View File

@ -4,10 +4,10 @@
#include "match.h"
#include "platform.h"
#include "project.h"
#include "timer.h"
#include <llvm/ADT/Twine.h>
#include <llvm/Support/Threading.h>
#include <llvm/Support/Timer.h>
using namespace llvm;
#include <thread>
@ -108,14 +108,14 @@ void IncludeComplete::Rescan() {
is_scanning = true;
std::thread([this]() {
set_thread_name("include");
Timer timer;
Timer timer("include", "scan include paths");
TimeRegion region(timer);
for (const std::string& dir : project_->quote_include_directories)
InsertIncludesFromDirectory(dir, false /*use_angle_brackets*/);
for (const std::string& dir : project_->angle_include_directories)
InsertIncludesFromDirectory(dir, true /*use_angle_brackets*/);
timer.ResetAndPrint("[perf] Scanning for includes");
is_scanning = false;
}).detach();
}

View File

@ -664,7 +664,7 @@ void OnIndexReference_Function(IndexFile* db,
case SymbolKind::Func: {
IndexFunc& parent = db->ToFunc(parent_cursor.cx_cursor);
parent.def.callees.push_back(
SymbolRef{loc, called.usr, SymbolKind::Func, role});
SymbolRef{{loc, called.usr, SymbolKind::Func, role}});
called.uses.push_back(Use{{loc, parent.usr, SymbolKind::Func, role}});
break;
}
@ -2011,8 +2011,7 @@ std::vector<std::unique_ptr<IndexFile>> ClangIndexer::Index(
VFS* vfs,
std::string file,
const std::vector<std::string>& args,
const std::vector<FileContents>& file_contents,
PerformanceImportFile* perf) {
const std::vector<FileContents>& file_contents) {
if (!g_config->index.enabled)
return {};
@ -2039,12 +2038,11 @@ std::vector<std::unique_ptr<IndexFile>> ClangIndexer::Index(
timer.stopTimer();
return ParseWithTu(vfs, perf, tu.get(), &index, file, args, unsaved_files);
return ParseWithTu(vfs, tu.get(), &index, file, args, unsaved_files);
}
std::vector<std::unique_ptr<IndexFile>> ParseWithTu(
VFS* vfs,
PerformanceImportFile* perf,
ClangTranslationUnit* tu,
ClangIndex* index,
const std::string& file,

View File

@ -21,12 +21,6 @@
#include <unordered_map>
#include <vector>
struct IndexFile;
struct IndexType;
struct IndexFunc;
struct IndexVar;
struct QueryFile;
struct SymbolIdx {
Usr usr;
SymbolKind kind;
@ -56,11 +50,7 @@ struct Reference {
};
// |id,kind| refer to the referenced entity.
struct SymbolRef : Reference {
SymbolRef() = default;
SymbolRef(Range range, Usr usr, SymbolKind kind, Role role)
: Reference{range, usr, kind, role} {}
};
struct SymbolRef : Reference {};
// Represents an occurrence of a variable/type, |usr,kind| refer to the lexical
// parent.
@ -322,7 +312,6 @@ struct NamespaceHelper {
std::vector<std::unique_ptr<IndexFile>> ParseWithTu(
VFS* vfs,
PerformanceImportFile* perf,
ClangTranslationUnit* tu,
ClangIndex* index,
const std::string& file,
@ -338,8 +327,7 @@ struct ClangIndexer {
VFS* vfs,
std::string file,
const std::vector<std::string>& args,
const std::vector<FileContents>& file_contents,
PerformanceImportFile* perf);
const std::vector<FileContents>& file_contents);
// Note: constructing this acquires a global lock
ClangIndex index;

View File

@ -3,7 +3,6 @@
#include "platform.h"
#include "project.h"
#include "pipeline.hh"
#include "timer.h"
#include "working_files.h"
using namespace ccls;

View File

@ -7,7 +7,6 @@
#include "platform.h"
#include "project.h"
#include "serializers/json.h"
#include "timer.h"
#include "working_files.h"
using namespace ccls;
@ -493,14 +492,11 @@ struct Handler_Initialize : BaseMessageHandler<In_InitializeRequest> {
sys::fs::create_directories(g_config->cacheDirectory + '@' +
EscapeFileName(g_config->projectRoot));
Timer time;
diag_engine->Init();
semantic_cache->Init();
// Open up / load the project.
project->Load(project_path);
time.ResetAndPrint("[perf] Loaded compilation entries (" +
std::to_string(project->entries.size()) + " files)");
// Start indexer threads. Start this after loading the project, as that
// may take a long time. Indexer threads will emit status/progress
@ -522,10 +518,8 @@ struct Handler_Initialize : BaseMessageHandler<In_InitializeRequest> {
// files, because that takes a long time.
include_complete->Rescan();
time.Reset();
LOG_S(INFO) << "dispatch initial index requests";
project->Index(working_files, request->id);
// We need to support multiple concurrent index processes.
time.ResetAndPrint("[perf] Dispatched initial index requests");
}
};
REGISTER_MESSAGE_HANDLER(Handler_Initialize);

View File

@ -3,10 +3,12 @@
#include "include_complete.h"
#include "message_handler.h"
#include "pipeline.hh"
#include "timer.h"
#include "working_files.h"
using namespace ccls;
#include <llvm/Support/Timer.h>
using namespace llvm;
#include <regex>
namespace {
@ -162,21 +164,8 @@ void FilterAndSortCompletionResponse(
if (!g_config->completion.filterAndSort)
return;
ScopedPerfTimer timer{"FilterAndSortCompletionResponse"};
// Used to inject more completions.
#if false
const size_t kNumIterations = 250;
size_t size = complete_response->result.items.size();
complete_response->result.items.reserve(size * (kNumIterations + 1));
for (size_t iteration = 0; iteration < kNumIterations; ++iteration) {
for (size_t i = 0; i < size; ++i) {
auto item = complete_response->result.items[i];
item.label += "#" + std::to_string(iteration);
complete_response->result.items.push_back(item);
}
}
#endif
Timer timer("FilterAndSortCompletionResponse", "");
TimeRegion region(timer);
auto& items = complete_response->result.items;

View File

@ -3,9 +3,8 @@
#include "message_handler.h"
#include "project.h"
#include "pipeline.hh"
using namespace ccls;
#include "timer.h"
#include "working_files.h"
using namespace ccls;
namespace {
MethodType kMethodType = "textDocument/didOpen";

View File

@ -2,7 +2,6 @@
#include "message_handler.h"
#include "pipeline.hh"
using namespace ccls;
#include "timer.h"
#include <stdint.h>
@ -142,7 +141,6 @@ struct Handler_TextDocumentSignatureHelp : MessageHandler {
// Set signature to what we parsed from the working file.
out.result.activeParameter = active_param;
Timer timer;
pipeline::WriteStdout(kMethodType, out);
if (!is_cached_result) {

View File

@ -2,9 +2,8 @@
#include "message_handler.h"
#include "project.h"
#include "pipeline.hh"
using namespace ccls;
#include "timer.h"
#include "working_files.h"
using namespace ccls;
namespace {
MethodType kMethodType = "workspace/didChangeConfiguration";
@ -25,15 +24,8 @@ struct Handler_WorkspaceDidChangeConfiguration
: BaseMessageHandler<In_WorkspaceDidChangeConfiguration> {
MethodType GetMethodType() const override { return kMethodType; }
void Run(In_WorkspaceDidChangeConfiguration* request) override {
Timer time;
project->Load(g_config->projectRoot);
time.ResetAndPrint("[perf] Loaded compilation entries (" +
std::to_string(project->entries.size()) + " files)");
time.Reset();
project->Index(working_files, lsRequestId());
time.ResetAndPrint(
"[perf] Dispatched workspace/didChangeConfiguration index requests");
clang_complete->FlushAllSessions();
}

View File

@ -26,11 +26,6 @@ struct Index_Request {
lsRequestId id;
};
struct Index_OnIndexed {
IndexUpdate update;
PerformanceImportFile perf;
};
struct Stdout_Request {
MethodType method;
std::string content;
@ -44,7 +39,7 @@ MultiQueueWaiter* indexer_waiter;
MultiQueueWaiter* stdout_waiter;
ThreadedQueue<std::unique_ptr<InMessage>>* on_request;
ThreadedQueue<Index_Request>* index_request;
ThreadedQueue<Index_OnIndexed>* on_indexed;
ThreadedQueue<IndexUpdate>* on_indexed;
ThreadedQueue<Stdout_Request>* for_stdout;
// Checks if |path| needs to be reparsed. This will modify cached state
@ -138,7 +133,7 @@ bool Indexer_Parse(DiagnosticsEngine* diag_engine,
if (request.path.empty()) {
IndexUpdate dummy;
dummy.refresh = true;
on_indexed->PushBack({std::move(dummy), PerformanceImportFile()}, false);
on_indexed->PushBack(std::move(dummy), false);
return false;
}
@ -185,17 +180,16 @@ bool Indexer_Parse(DiagnosticsEngine* diag_engine,
}
if (reparse < 2) {
PerformanceImportFile perf;
auto dependencies = prev->dependencies;
if (reparse) {
IndexUpdate update = IndexUpdate::CreateDelta(nullptr, prev.get());
on_indexed->PushBack({std::move(update), perf}, request.is_interactive);
on_indexed->PushBack(std::move(update), request.is_interactive);
}
for (const auto& dep : dependencies)
if (vfs->Mark(dep.first().str(), 0, 2)) {
prev = RawCacheLoad(dep.first().str());
IndexUpdate update = IndexUpdate::CreateDelta(nullptr, prev.get());
on_indexed->PushBack({std::move(update), perf}, request.is_interactive);
on_indexed->PushBack(std::move(update), request.is_interactive);
}
std::lock_guard<std::mutex> lock(vfs->mutex);
@ -207,8 +201,7 @@ bool Indexer_Parse(DiagnosticsEngine* diag_engine,
LOG_S(INFO) << "parse " << path_to_index;
PerformanceImportFile perf;
auto indexes = indexer->Index(vfs, path_to_index, entry.args, {}, &perf);
auto indexes = indexer->Index(vfs, path_to_index, entry.args, {});
if (indexes.empty()) {
if (g_config->index.enabled && request.id.Valid()) {
@ -258,7 +251,7 @@ bool Indexer_Parse(DiagnosticsEngine* diag_engine,
IndexUpdate update = IndexUpdate::CreateDelta(prev.get(), curr.get());
LOG_S(INFO) << "built index for " << path << " (is_delta=" << !!prev << ")";
on_indexed->PushBack({std::move(update), perf}, request.is_interactive);
on_indexed->PushBack(std::move(update), request.is_interactive);
}
return true;
@ -269,7 +262,7 @@ bool Indexer_Parse(DiagnosticsEngine* diag_engine,
void Init() {
main_waiter = new MultiQueueWaiter;
on_request = new ThreadedQueue<std::unique_ptr<InMessage>>(main_waiter);
on_indexed = new ThreadedQueue<Index_OnIndexed>(main_waiter);
on_indexed = new ThreadedQueue<IndexUpdate>(main_waiter);
indexer_waiter = new MultiQueueWaiter;
index_request = new ThreadedQueue<Index_Request>(indexer_waiter);
@ -293,8 +286,8 @@ void Indexer_Main(DiagnosticsEngine* diag_engine,
void Main_OnIndexed(DB* db,
SemanticHighlightSymbolCache* semantic_cache,
WorkingFiles* working_files,
Index_OnIndexed* response) {
if (response->update.refresh) {
IndexUpdate* update) {
if (update->refresh) {
LOG_S(INFO) << "Loaded project. Refresh semantic highlight for all working file.";
std::lock_guard<std::mutex> lock(working_files->files_mutex);
for (auto& f : working_files->files) {
@ -309,26 +302,19 @@ void Main_OnIndexed(DB* db,
Timer timer("apply", "apply index");
timer.startTimer();
db->ApplyIndexUpdate(&response->update);
db->ApplyIndexUpdate(update);
timer.stopTimer();
// Update indexed content, inactive lines, and semantic highlighting.
if (response->update.files_def_update) {
auto& update = *response->update.files_def_update;
LOG_S(INFO) << "apply index for " << update.first.path;
if (update->files_def_update) {
auto& def_u = *update->files_def_update;
LOG_S(INFO) << "apply index for " << def_u.first.path;
if (WorkingFile* working_file =
working_files->GetFileByFilename(update.first.path)) {
// Update indexed content.
working_file->SetIndexContent(update.second);
// Inactive lines.
EmitInactiveLines(working_file, update.first.inactive_regions);
// Semantic highlighting.
int file_id =
db->name2file_id[LowerPathIfInsensitive(working_file->filename)];
QueryFile* file = &db->files[file_id];
EmitSemanticHighlighting(db, semantic_cache, working_file, file);
working_files->GetFileByFilename(def_u.first.path)) {
working_file->SetIndexContent(def_u.second);
EmitInactiveLines(working_file, def_u.first.inactive_regions);
EmitSemanticHighlighting(db, semantic_cache, working_file,
&db->files[update->file_id]);
}
}
}
@ -454,11 +440,11 @@ void MainLoop() {
}
for (int i = 80; i--;) {
std::optional<Index_OnIndexed> response = on_indexed->TryPopFront();
if (!response)
std::optional<IndexUpdate> update = on_indexed->TryPopFront();
if (!update)
break;
did_work = true;
Main_OnIndexed(&db, &semantic_cache, &working_files, &*response);
Main_OnIndexed(&db, &semantic_cache, &working_files, &*update);
}
// Cleanup and free any unused memory.

View File

@ -1,7 +1,5 @@
#pragma once
#include <memory>
#include <optional>
#include <string>
#include <string_view>
#include <vector>

View File

@ -8,7 +8,6 @@
#include "platform.h"
#include "pipeline.hh"
#include "serializers/json.h"
#include "timer.h"
#include "utils.h"
#include "working_files.h"
using namespace ccls;
@ -275,20 +274,12 @@ std::vector<Project::Entry> LoadCompilationEntriesFromDirectory(
LOG_S(INFO) << "loaded " << Path.c_str();
Timer clang_time;
Timer our_time;
clang_time.Pause();
our_time.Pause();
clang_time.Resume();
CXCompileCommands cx_commands =
clang_CompilationDatabase_getAllCompileCommands(cx_db);
unsigned int num_commands = clang_CompileCommands_getSize(cx_commands);
clang_time.Pause();
std::vector<Project::Entry> result;
for (unsigned int i = 0; i < num_commands; i++) {
clang_time.Resume();
CXCompileCommand cx_command =
clang_CompileCommands_getCommand(cx_commands, i);
@ -304,25 +295,16 @@ std::vector<Project::Entry> LoadCompilationEntriesFromDirectory(
entry.args.push_back(
ToString(clang_CompileCommand_getArg(cx_command, j)));
}
clang_time.Pause(); // TODO: don't call ToString in this block.
// LOG_S(INFO) << "Got args " << StringJoin(entry.args);
our_time.Resume();
entry.directory = directory;
entry.file = entry.ResolveIfRelative(relative_filename);
result.push_back(
GetCompilationEntryFromCompileCommandEntry(project, entry));
our_time.Pause();
}
clang_time.Resume();
clang_CompileCommands_dispose(cx_commands);
clang_CompilationDatabase_dispose(cx_db);
clang_time.Pause();
clang_time.ResetAndPrint("compile_commands.json clang time");
our_time.ResetAndPrint("compile_commands.json our time");
return result;
}

View File

@ -80,10 +80,10 @@ QueryFile::DefUpdate BuildFileDefUpdate(const IndexFile& indexed) {
def.language = indexed.language;
auto add_all_symbols = [&](Use use, Usr usr, SymbolKind kind) {
def.all_symbols.push_back(SymbolRef(use.range, usr, kind, use.role));
def.all_symbols.push_back(SymbolRef{{use.range, usr, kind, use.role}});
};
auto add_outline = [&](Use use, Usr usr, SymbolKind kind) {
def.outline.push_back(SymbolRef(use.range, usr, kind, use.role));
def.outline.push_back(SymbolRef{{use.range, usr, kind, use.role}});
};
for (auto& it : indexed.usr2type) {

View File

@ -290,8 +290,7 @@ bool RunIndexTests(const std::string& filter_path, bool enable_update) {
// Run test.
g_config = std::make_unique<Config>();
VFS vfs;
PerformanceImportFile perf;
auto dbs = index.Index(&vfs, path, flags, {}, &perf);
auto dbs = index.Index(&vfs, path, flags, {});
for (const auto& entry : all_expected_output) {
const std::string& expected_path = entry.first;

View File

@ -1,51 +0,0 @@
#include "timer.h"
#include "log.hh"
Timer::Timer() {
Reset();
}
long long Timer::ElapsedMicroseconds() const {
std::chrono::time_point<Clock> end = Clock::now();
return elapsed_ +
std::chrono::duration_cast<std::chrono::microseconds>(end - start_)
.count();
}
long long Timer::ElapsedMicrosecondsAndReset() {
long long elapsed = ElapsedMicroseconds();
Reset();
return elapsed;
}
void Timer::Reset() {
start_ = Clock::now();
elapsed_ = 0;
}
void Timer::ResetAndPrint(const std::string& message) {
long long elapsed = ElapsedMicroseconds();
long long milliseconds = elapsed / 1000;
long long remaining = elapsed - milliseconds;
LOG_S(INFO) << message << " took " << milliseconds << "." << remaining
<< "ms";
Reset();
}
void Timer::Pause() {
std::chrono::time_point<Clock> end = Clock::now();
long long elapsed =
std::chrono::duration_cast<std::chrono::microseconds>(end - start_)
.count();
elapsed_ += elapsed;
}
void Timer::Resume() {
start_ = Clock::now();
}
ScopedPerfTimer::~ScopedPerfTimer() {
timer_.ResetAndPrint(message_);
}

View File

@ -1,36 +0,0 @@
#pragma once
#include <chrono>
#include <string>
struct Timer {
using Clock = std::chrono::high_resolution_clock;
// Creates a new timer. A timer is always running.
Timer();
// Returns elapsed microseconds.
long long ElapsedMicroseconds() const;
// Returns elapsed microseconds and restarts/resets the timer.
long long ElapsedMicrosecondsAndReset();
// Restart/reset the timer.
void Reset();
// Resets timer and prints a message like "<foo> took 5ms"
void ResetAndPrint(const std::string& message);
// Pause the timer.
void Pause();
// Resume the timer after it has been paused.
void Resume();
// Raw start time.
std::chrono::time_point<Clock> start_;
// Elapsed time.
long long elapsed_;
};
struct ScopedPerfTimer {
~ScopedPerfTimer();
std::string message_;
Timer timer_;
};