wip

system/proclogd/SConscript

@@ -0,0 +1,6 @@
+Import('env', 'cereal', 'messaging', 'common')
+libs = [cereal, messaging, 'pthread', 'zmq', 'capnp', 'kj', 'common', 'zmq', 'json11']
+env.Program('proclogd', ['main.cc', 'proclog.cc'], LIBS=libs)
+
+if GetOption('extras'):
+  env.Program('tests/test_proclog', ['tests/test_proclog.cc', 'proclog.cc'], LIBS=libs)

system/proclogd/main.cc

@@ -0,0 +1,25 @@
+
+#include <sys/resource.h>
+
+#include "common/ratekeeper.h"
+#include "common/util.h"
+#include "system/proclogd/proclog.h"
+
+ExitHandler do_exit;
+
+int main(int argc, char **argv) {
+  setpriority(PRIO_PROCESS, 0, -15);
+
+  RateKeeper rk("proclogd", 0.5);
+  PubMaster publisher({"procLog"});
+
+  while (!do_exit) {
+    MessageBuilder msg;
+    buildProcLogMessage(msg);
+    publisher.send("procLog", msg);
+
+    rk.keepTime();
+  }
+
+  return 0;
+}

system/proclogd/proclog.cc

@@ -0,0 +1,239 @@
+#include "system/proclogd/proclog.h"
+
+#include <dirent.h>
+
+#include <cassert>
+#include <fstream>
+#include <iterator>
+#include <sstream>
+
+#include "common/swaglog.h"
+#include "common/util.h"
+
+namespace Parser {
+
+// parse /proc/stat
+std::vector<CPUTime> cpuTimes(std::istream &stream) {
+  std::vector<CPUTime> cpu_times;
+  std::string line;
+  // skip the first line for cpu total
+  std::getline(stream, line);
+  while (std::getline(stream, line)) {
+    if (line.compare(0, 3, "cpu") != 0) break;
+
+    CPUTime t = {};
+    std::istringstream iss(line);
+    if (iss.ignore(3) >> t.id >> t.utime >> t.ntime >> t.stime >> t.itime >> t.iowtime >> t.irqtime >> t.sirqtime)
+      cpu_times.push_back(t);
+  }
+  return cpu_times;
+}
+
+// parse /proc/meminfo
+std::unordered_map<std::string, uint64_t> memInfo(std::istream &stream) {
+  std::unordered_map<std::string, uint64_t> mem_info;
+  std::string line, key;
+  while (std::getline(stream, line)) {
+    uint64_t val = 0;
+    std::istringstream iss(line);
+    if (iss >> key >> val) {
+      mem_info[key] = val * 1024;
+    }
+  }
+  return mem_info;
+}
+
+// field position (https://man7.org/linux/man-pages/man5/proc.5.html)
+enum StatPos {
+  pid = 1,
+  state = 3,
+  ppid = 4,
+  utime = 14,
+  stime = 15,
+  cutime = 16,
+  cstime = 17,
+  priority = 18,
+  nice = 19,
+  num_threads = 20,
+  starttime = 22,
+  vsize = 23,
+  rss = 24,
+  processor = 39,
+  MAX_FIELD = 52,
+};
+
+// parse /proc/pid/stat
+std::optional<ProcStat> procStat(std::string stat) {
+  // To avoid being fooled by names containing a closing paren, scan backwards.
+  auto open_paren = stat.find('(');
+  auto close_paren = stat.rfind(')');
+  if (open_paren == std::string::npos || close_paren == std::string::npos || open_paren > close_paren) {
+    return std::nullopt;
+  }
+
+  std::string name = stat.substr(open_paren + 1, close_paren - open_paren - 1);
+  // replace space in name with _
+  std::replace(&stat[open_paren], &stat[close_paren], ' ', '_');
+  std::istringstream iss(stat);
+  std::vector<std::string> v{std::istream_iterator<std::string>(iss),
+                             std::istream_iterator<std::string>()};
+  try {
+    if (v.size() != StatPos::MAX_FIELD) {
+      throw std::invalid_argument("stat");
+    }
+    ProcStat p = {
+      .name = name,
+      .pid = stoi(v[StatPos::pid - 1]),
+      .state = v[StatPos::state - 1][0],
+      .ppid = stoi(v[StatPos::ppid - 1]),
+      .utime = stoul(v[StatPos::utime - 1]),
+      .stime = stoul(v[StatPos::stime - 1]),
+      .cutime = stol(v[StatPos::cutime - 1]),
+      .cstime = stol(v[StatPos::cstime - 1]),
+      .priority = stol(v[StatPos::priority - 1]),
+      .nice = stol(v[StatPos::nice - 1]),
+      .num_threads = stol(v[StatPos::num_threads - 1]),
+      .starttime = stoull(v[StatPos::starttime - 1]),
+      .vms = stoul(v[StatPos::vsize - 1]),
+      .rss = stol(v[StatPos::rss - 1]),
+      .processor = stoi(v[StatPos::processor - 1]),
+    };
+    return p;
+  } catch (const std::invalid_argument &e) {
+    LOGE("failed to parse procStat (%s) :%s", e.what(), stat.c_str());
+  } catch (const std::out_of_range &e) {
+    LOGE("failed to parse procStat (%s) :%s", e.what(), stat.c_str());
+  }
+  return std::nullopt;
+}
+
+// return list of PIDs from /proc
+std::vector<int> pids() {
+  std::vector<int> ids;
+  DIR *d = opendir("/proc");
+  assert(d);
+  char *p_end;
+  struct dirent *de = NULL;
+  while ((de = readdir(d))) {
+    if (de->d_type == DT_DIR) {
+      int pid = strtol(de->d_name, &p_end, 10);
+      if (p_end == (de->d_name + strlen(de->d_name))) {
+        ids.push_back(pid);
+      }
+    }
+  }
+  closedir(d);
+  return ids;
+}
+
+// null-delimited cmdline arguments to vector
+std::vector<std::string> cmdline(std::istream &stream) {
+  std::vector<std::string> ret;
+  std::string line;
+  while (std::getline(stream, line, '\0')) {
+    if (!line.empty()) {
+      ret.push_back(line);
+    }
+  }
+  return ret;
+}
+
+const ProcCache &getProcExtraInfo(int pid, const std::string &name) {
+  static std::unordered_map<pid_t, ProcCache> proc_cache;
+  ProcCache &cache = proc_cache[pid];
+  if (cache.pid != pid || cache.name != name) {
+    cache.pid = pid;
+    cache.name = name;
+    std::string proc_path = "/proc/" + std::to_string(pid);
+    cache.exe = util::readlink(proc_path + "/exe");
+    std::ifstream stream(proc_path + "/cmdline");
+    cache.cmdline = cmdline(stream);
+  }
+  return cache;
+}
+
+}  // namespace Parser
+
+const double jiffy = sysconf(_SC_CLK_TCK);
+const size_t page_size = sysconf(_SC_PAGE_SIZE);
+
+void buildCPUTimes(cereal::ProcLog::Builder &builder) {
+  std::ifstream stream("/proc/stat");
+  std::vector<CPUTime> stats = Parser::cpuTimes(stream);
+
+  auto log_cpu_times = builder.initCpuTimes(stats.size());
+  for (int i = 0; i < stats.size(); ++i) {
+    auto l = log_cpu_times[i];
+    const CPUTime &r = stats[i];
+    l.setCpuNum(r.id);
+    l.setUser(r.utime / jiffy);
+    l.setNice(r.ntime / jiffy);
+    l.setSystem(r.stime / jiffy);
+    l.setIdle(r.itime / jiffy);
+    l.setIowait(r.iowtime / jiffy);
+    l.setIrq(r.irqtime / jiffy);
+    l.setSoftirq(r.sirqtime / jiffy);
+  }
+}
+
+void buildMemInfo(cereal::ProcLog::Builder &builder) {
+  std::ifstream stream("/proc/meminfo");
+  auto mem_info = Parser::memInfo(stream);
+
+  auto mem = builder.initMem();
+  mem.setTotal(mem_info["MemTotal:"]);
+  mem.setFree(mem_info["MemFree:"]);
+  mem.setAvailable(mem_info["MemAvailable:"]);
+  mem.setBuffers(mem_info["Buffers:"]);
+  mem.setCached(mem_info["Cached:"]);
+  mem.setActive(mem_info["Active:"]);
+  mem.setInactive(mem_info["Inactive:"]);
+  mem.setShared(mem_info["Shmem:"]);
+}
+
+void buildProcs(cereal::ProcLog::Builder &builder) {
+  auto pids = Parser::pids();
+  std::vector<ProcStat> proc_stats;
+  proc_stats.reserve(pids.size());
+  for (int pid : pids) {
+    std::string path = "/proc/" + std::to_string(pid) + "/stat";
+    if (auto stat = Parser::procStat(util::read_file(path))) {
+      proc_stats.push_back(*stat);
+    }
+  }
+
+  auto procs = builder.initProcs(proc_stats.size());
+  for (size_t i = 0; i < proc_stats.size(); i++) {
+    auto l = procs[i];
+    const ProcStat &r = proc_stats[i];
+    l.setPid(r.pid);
+    l.setState(r.state);
+    l.setPpid(r.ppid);
+    l.setCpuUser(r.utime / jiffy);
+    l.setCpuSystem(r.stime / jiffy);
+    l.setCpuChildrenUser(r.cutime / jiffy);
+    l.setCpuChildrenSystem(r.cstime / jiffy);
+    l.setPriority(r.priority);
+    l.setNice(r.nice);
+    l.setNumThreads(r.num_threads);
+    l.setStartTime(r.starttime / jiffy);
+    l.setMemVms(r.vms);
+    l.setMemRss((uint64_t)r.rss * page_size);
+    l.setProcessor(r.processor);
+    l.setName(r.name);
+
+    const ProcCache &extra_info = Parser::getProcExtraInfo(r.pid, r.name);
+    l.setExe(extra_info.exe);
+    auto lcmdline = l.initCmdline(extra_info.cmdline.size());
+    for (size_t j = 0; j < lcmdline.size(); j++) {
+      lcmdline.set(j, extra_info.cmdline[j]);
+    }
+  }
+}
+
+void buildProcLogMessage(MessageBuilder &msg) {
+  auto procLog = msg.initEvent().initProcLog();
+  buildProcs(procLog);
+  buildCPUTimes(procLog);
+  buildMemInfo(procLog);
+}

system/proclogd/proclog.h

@@ -0,0 +1,40 @@
+#include <optional>
+#include <string>
+#include <unordered_map>
+#include <vector>
+
+#include "cereal/messaging/messaging.h"
+
+struct CPUTime {
+  int id;
+  unsigned long utime, ntime, stime, itime;
+  unsigned long iowtime, irqtime, sirqtime;
+};
+
+struct ProcCache {
+  int pid;
+  std::string name, exe;
+  std::vector<std::string> cmdline;
+};
+
+struct ProcStat {
+  int pid, ppid, processor;
+  char state;
+  long cutime, cstime, priority, nice, num_threads, rss;
+  unsigned long utime, stime, vms;
+  unsigned long long starttime;
+  std::string name;
+};
+
+namespace Parser {
+
+std::vector<int> pids();
+std::optional<ProcStat> procStat(std::string stat);
+std::vector<std::string> cmdline(std::istream &stream);
+std::vector<CPUTime> cpuTimes(std::istream &stream);
+std::unordered_map<std::string, uint64_t> memInfo(std::istream &stream);
+const ProcCache &getProcExtraInfo(int pid, const std::string &name);
+
+};  // namespace Parser
+
+void buildProcLogMessage(MessageBuilder &msg);

system/proclogd/tests/.gitignore

@@ -0,0 +1 @@
+test_proclog

system/proclogd/tests/test_proclog.cc

@@ -0,0 +1,142 @@
+#define CATCH_CONFIG_MAIN
+#include "catch2/catch.hpp"
+#include "common/util.h"
+#include "system/proclogd/proclog.h"
+
+const std::string allowed_states = "RSDTZtWXxKWPI";
+
+TEST_CASE("Parser::procStat") {
+  SECTION("from string") {
+    const std::string stat_str =
+        "33012 (code )) S 32978 6620 6620 0 -1 4194368 2042377 0 144 0 24510 11627 0 "
+        "0 20 0 39 0 53077 830029824 62214 18446744073709551615 94257242783744 94257366235808 "
+        "140735738643248 0 0 0 0 4098 1073808632 0 0 0 17 2 0 0 2 0 0 94257370858656 94257371248232 "
+        "94257404952576 140735738648768 140735738648823 140735738648823 140735738650595 0";
+    auto stat = Parser::procStat(stat_str);
+    REQUIRE(stat);
+    REQUIRE(stat->pid == 33012);
+    REQUIRE(stat->name == "code )");
+    REQUIRE(stat->state == 'S');
+    REQUIRE(stat->ppid == 32978);
+    REQUIRE(stat->utime == 24510);
+    REQUIRE(stat->stime == 11627);
+    REQUIRE(stat->cutime == 0);
+    REQUIRE(stat->cstime == 0);
+    REQUIRE(stat->priority == 20);
+    REQUIRE(stat->nice == 0);
+    REQUIRE(stat->num_threads == 39);
+    REQUIRE(stat->starttime == 53077);
+    REQUIRE(stat->vms == 830029824);
+    REQUIRE(stat->rss == 62214);
+    REQUIRE(stat->processor == 2);
+  }
+  SECTION("all processes") {
+    std::vector<int> pids = Parser::pids();
+    REQUIRE(pids.size() > 1);
+    for (int pid : pids) {
+      std::string stat_path = "/proc/" + std::to_string(pid) + "/stat";
+      INFO(stat_path);
+      if (auto stat = Parser::procStat(util::read_file(stat_path))) {
+        REQUIRE(stat->pid == pid);
+        REQUIRE(allowed_states.find(stat->state) != std::string::npos);
+      } else {
+        REQUIRE(util::file_exists(stat_path) == false);
+      }
+    }
+  }
+}
+
+TEST_CASE("Parser::cpuTimes") {
+  SECTION("from string") {
+    std::string stat =
+        "cpu  0 0 0 0 0 0 0 0 0 0\n"
+        "cpu0 1 2 3 4 5 6 7 8 9 10\n"
+        "cpu1 1 2 3 4 5 6 7 8 9 10\n";
+    std::istringstream stream(stat);
+    auto stats = Parser::cpuTimes(stream);
+    REQUIRE(stats.size() == 2);
+    for (int i = 0; i < stats.size(); ++i) {
+      REQUIRE(stats[i].id == i);
+      REQUIRE(stats[i].utime == 1);
+      REQUIRE(stats[i].ntime ==2);
+      REQUIRE(stats[i].stime == 3);
+      REQUIRE(stats[i].itime == 4);
+      REQUIRE(stats[i].iowtime == 5);
+      REQUIRE(stats[i].irqtime == 6);
+      REQUIRE(stats[i].sirqtime == 7);
+    }
+  }
+  SECTION("all cpus") {
+    std::istringstream stream(util::read_file("/proc/stat"));
+    auto stats = Parser::cpuTimes(stream);
+    REQUIRE(stats.size() == sysconf(_SC_NPROCESSORS_ONLN));
+    for (int i = 0; i < stats.size(); ++i) {
+      REQUIRE(stats[i].id == i);
+    }
+  }
+}
+
+TEST_CASE("Parser::memInfo") {
+  SECTION("from string") {
+    std::istringstream stream("MemTotal:    1024 kb\nMemFree:    2048 kb\n");
+    auto meminfo = Parser::memInfo(stream);
+    REQUIRE(meminfo["MemTotal:"] == 1024 * 1024);
+    REQUIRE(meminfo["MemFree:"] == 2048 * 1024);
+  }
+  SECTION("from /proc/meminfo") {
+    std::string require_keys[] = {"MemTotal:", "MemFree:", "MemAvailable:", "Buffers:", "Cached:", "Active:", "Inactive:", "Shmem:"};
+    std::istringstream stream(util::read_file("/proc/meminfo"));
+    auto meminfo = Parser::memInfo(stream);
+    for (auto &key : require_keys) {
+      REQUIRE(meminfo.find(key) != meminfo.end());
+      REQUIRE(meminfo[key] > 0);
+    }
+  }
+}
+
+void test_cmdline(std::string cmdline, const std::vector<std::string> requires) {
+  std::stringstream ss;
+  ss.write(&cmdline[0], cmdline.size());
+  auto cmds = Parser::cmdline(ss);
+  REQUIRE(cmds.size() == requires.size());
+  for (int i = 0; i < requires.size(); ++i) {
+    REQUIRE(cmds[i] == requires[i]);
+  }
+}
+TEST_CASE("Parser::cmdline") {
+  test_cmdline(std::string("a\0b\0c\0", 7), {"a", "b", "c"});
+  test_cmdline(std::string("a\0\0c\0", 6), {"a", "c"});
+  test_cmdline(std::string("a\0b\0c\0\0\0", 9), {"a", "b", "c"});
+}
+
+TEST_CASE("buildProcLoggerMessage") {
+  MessageBuilder msg;
+  buildProcLogMessage(msg);
+
+  kj::Array<capnp::word> buf = capnp::messageToFlatArray(msg);
+  capnp::FlatArrayMessageReader reader(buf);
+  auto log = reader.getRoot<cereal::Event>().getProcLog();
+  REQUIRE(log.totalSize().wordCount > 0);
+
+  // test cereal::ProcLog::CPUTimes
+  auto cpu_times = log.getCpuTimes();
+  REQUIRE(cpu_times.size() == sysconf(_SC_NPROCESSORS_ONLN));
+  REQUIRE(cpu_times[cpu_times.size() - 1].getCpuNum() == cpu_times.size() - 1);
+
+  // test cereal::ProcLog::Mem
+  auto mem = log.getMem();
+  REQUIRE(mem.getTotal() > 0);
+  REQUIRE(mem.getShared() > 0);
+
+  // test cereal::ProcLog::Process
+  auto procs = log.getProcs();
+  for (auto p : procs) {
+    REQUIRE(allowed_states.find(p.getState()) != std::string::npos);
+    if (p.getPid() == ::getpid()) {
+      REQUIRE(p.getName() == "test_proclog");
+      REQUIRE(p.getState() == 'R');
+      REQUIRE_THAT(p.getExe().cStr(), Catch::Matchers::Contains("test_proclog"));
+      REQUIRE_THAT(p.getCmdline()[0], Catch::Matchers::Contains("test_proclog"));
+    }
+  }
+}