verbose pipeline logging

src/log.cc

@@ -29,6 +29,13 @@ static std::mutex mtx;
 FILE *file;
 Verbosity verbosity;
 
+bool SetVerbosity(int value) {
+  verbosity = static_cast<Verbosity>(value);
+  if (value > Verbosity_DEBUG || value < Verbosity_FATAL)
+    return false;
+  return true;
+}
+
 Message::Message(Verbosity verbosity, const char *file, int line)
     : verbosity_(verbosity) {
   using namespace llvm;
@@ -60,6 +67,7 @@ Message::Message(Verbosity verbosity, const char *file, int line)
     case Verbosity_ERROR: stream_ << 'E'; break;
     case Verbosity_WARNING: stream_ << 'W'; break;
     case Verbosity_INFO: stream_ << 'I'; break;
+    case Verbosity_DEBUG: stream_ << 'D'; break;
     default: stream_ << "V(" << int(verbosity_) << ')';
   }
   // clang-format on

src/log.hh

@@ -15,8 +15,11 @@ enum Verbosity {
   Verbosity_ERROR = -2,
   Verbosity_WARNING = -1,
   Verbosity_INFO = 0,
+  Verbosity_DEBUG = 1,
 };
+
 extern Verbosity verbosity;
+bool SetVerbosity(int value);
 
 struct Message {
   std::stringstream stream_;

src/main.cc

@@ -49,7 +49,7 @@ namespace {
 OptionCategory C("ccls options");
 
 opt<bool> opt_help("h", desc("Alias for -help"), cat(C));
-opt<int> opt_verbose("v", desc("verbosity"), init(0), cat(C));
+opt<int> opt_verbose("v", desc("verbosity, 0 default. From 1 (debug) to -3 (critical)"), init(0), cat(C));
 opt<std::string> opt_test_index("test-index", ValueOptional, init("!"),
                                 desc("run index tests"), cat(C));
 
@@ -86,7 +86,11 @@ int main(int argc, char **argv) {
     PrintHelpMessage();
     return 0;
   }
-  ccls::log::verbosity = ccls::log::Verbosity(opt_verbose.getValue());
+
+  if (!ccls::log::SetVerbosity(opt_verbose.getValue())) {
+    fprintf(stderr, "Unsupported verbosity level set\n");
+  }
+
 
   pipeline::Init();
   const char *env = getenv("CCLS_CRASH_RECOVERY");

src/pipeline.cc

@@ -35,6 +35,7 @@ limitations under the License.
 
 #include <chrono>
 #include <mutex>
+#include <charconv>
 #include <shared_mutex>
 #include <thread>
 #ifndef _WIN32
@@ -479,56 +480,89 @@ void Main_OnIndexed(DB *db, WorkingFiles *wfiles, IndexUpdate *update) {
   }
 }
 
+std::size_t ReadHeader(bool* eof, std::string* str) {
+  static const std::string_view kContentLength("Content-Length: ");
+  str->clear();
+  while (true) {
+    int c = getchar();
+    if (c == EOF) {
+      *eof = true;
+      return 0;
+    }
+    if (c == '\n') {
+      if (str->empty()) {
+        break;
+      }
+      if (str->compare(0, kContentLength.size(), kContentLength)) {
+        LOG_S(WARNING) << "Unknown header";
+        break;
+      }
+      std::size_t len;
+      auto result = std::from_chars(str->c_str() + kContentLength.size(), str->c_str() + str->size(), len);
+      if (result.ec != std::errc()) {
+        LOG_S(WARNING) << "Content-Length parse error";
+        break;
+      }
+      return len;
+    } else if (c != '\r') {
+      str->push_back(c);
+    }
+  }
+  return 0;
+}
+
 void LaunchStdin() {
   ThreadEnter();
   std::thread([]() {
     set_thread_name("stdin");
+    bool eof = false;
     std::string str;
-    const std::string_view kContentLength("Content-Length: ");
+    while (!eof) {
-    while (true) {
+      std::size_t len = ReadHeader(&eof, &str); // read Content-Length
-      int len = 0;
+      if (eof)
-      str.clear();
-      while (true) {
-        int c = getchar();
-        if (c == EOF)
         return;
-        if (c == '\n') {
+      if (len == 0)
-          if (str.empty())
+        continue;
-            break;
+      ReadHeader(&eof, &str); // read empty line
-          if (!str.compare(0, kContentLength.size(), kContentLength))
+      if (eof)
-            len = atoi(str.c_str() + kContentLength.size());
-          str.clear();
-        } else if (c != '\r') {
-          str += c;
-        }
-      }
-
-      str.resize(len);
-      for (int i = 0; i < len; ++i) {
-        int c = getchar();
-        if (c == EOF)
         return;
-        str[i] = c;
+      str.clear();
+      str.reserve(len);
+      for (std::size_t i = 0; i < len; ++i) {
+        int c = getchar();
+        if (c == EOF) {
+          eof = true;
+          return;
+        }
+        str.push_back(c);
       }
 
       auto message = std::make_unique<char[]>(len);
       std::copy(str.begin(), str.end(), message.get());
       auto document = std::make_unique<rapidjson::Document>();
       document->Parse(message.get(), len);
-      assert(!document->HasParseError());
+      if (document->HasParseError()) {
+        LOG_S(WARNING) << "Json parse error";
+        continue;
+      }
 
       JsonReader reader{document.get()};
       if (!reader.m->HasMember("jsonrpc") ||
-          std::string((*reader.m)["jsonrpc"].GetString()) != "2.0")
+          std::string((*reader.m)["jsonrpc"].GetString()) != "2.0") {
-        break;
+        LOG_S(WARNING) << "Bad jsonrpc member";
+        continue;
+      }
       RequestId id;
       std::string method;
       ReflectMember(reader, "id", id);
       ReflectMember(reader, "method", method);
-      if (method.empty())
+      if (method.empty()) {
+        LOG_S(WARNING) << "Empty method";
         continue;
+      }
       bool should_exit = method == "exit";
       // g_config is not available before "initialize". Use 0 in that case.
+      LOG_S(DEBUG) << "Received method: " << method;
       on_request->PushBack(
           {id, std::move(method), std::move(message), std::move(document),
            chrono::steady_clock::now() +
@@ -738,6 +772,7 @@ void NotifyOrRequest(const char *method, bool request,
   JsonWriter writer(&w);
   fn(writer);
   w.EndObject();
+  LOG_S(DEBUG) << "Notify/Request sent " << method;
   for_stdout->PushBack(output.GetString());
 }
 
@@ -765,6 +800,7 @@ static void Reply(RequestId id, const char *key,
   JsonWriter writer(&w);
   fn(writer);
   w.EndObject();
+  LOG_S(DEBUG) << "Reply sent: " << id.value;
   for_stdout->PushBack(output.GetString());
 }