fix(profiler): no such file /proc/{pid}/task (#117)

* fix(profiler): ensure failure if profiling script fails

* docs(cpp): update docs to run c++ profiler

* refactor(cpp): move logic to function

* chore(cpp): throw custom error if directory not found

* refactor: move some test utils to e2e folder

* refactor(test): separate between atrace mock and profiler mock

* refactor(test): fix some typings

* refactor(profiler): add logStderr option

* refactor(profiler): pass errors on stderr instead of stdout

* fix(profiler): reset measures if pid changes

Pid can change if app is restarted in the background

* chore(cpp): recompile executables

* fix(profiler): ensure graceful kill doesn't throw error

* chore: fix comment

packages/android-performance-profiler/cpp-profiler/README.md

@@ -21,5 +21,5 @@ then you can run with:
 ```sh
 ./run.sh [command] <arguments>
 # For instance
-./run.sh pollPerformanceMeasures $(adb shell pidof com.example)
+./run.sh pollPerformanceMeasures com.example 500
 ```

packages/android-performance-profiler/cpp-profiler/run.sh

@@ -2,4 +2,4 @@
 
 cmake --build .
 adb push BAMPerfProfiler /data/local/tmp/BAMPerfProfiler
-adb shell /data/local/tmp/BAMPerfProfiler $1 $2
+adb shell /data/local/tmp/BAMPerfProfiler $1 $2 $3

packages/android-performance-profiler/cpp-profiler/src/main.cpp

@@ -8,6 +8,7 @@
 #include <unistd.h>
 #include "utils.h"
 
+using std::cerr;
 using std::cout;
 using std::endl;
 using std::string;
@@ -28,14 +29,26 @@ void readFile(string filePath)
     }
     else
     {
-        cout << "C++ Error, file couldn't be opened" << endl;
+        cerr << "CPP_ERROR_CANNOT_OPEN_FILE " + filePath << endl;
     }
 }
 
+class PidClosedError : public std::runtime_error
+{
+public:
+    PidClosedError(const std::string &message)
+        : std::runtime_error(message) {}
+};
+
 void printCpuStats(string pid)
 {
     string path = "/proc/" + pid + "/task";
 
+    if (!fs::exists(path))
+    {
+        throw PidClosedError("Directory does not exist: " + path);
+    }
+
     for (const auto &entry : fs::directory_iterator(path))
     {
         string subProcessPath = entry.path().string() + "/stat";
@@ -86,13 +99,46 @@ long long printPerformanceMeasure(string pid)
     return totalDuration.count();
 }
 
-void pollPerformanceMeasures(std::string pid, int interval)
+std::string pidOf(string bundleId)
 {
-    while (true)
+    auto result = executeCommand("pidof " + bundleId);
+    return result.substr(0, result.find_first_of("\n"));
+}
+
+void pollPerformanceMeasures(std::string bundleId, int interval)
+{
+    string pid = "";
+
+    // We read atrace lines before the app is started
+    // since it can take a bit of time to start and clear the traceOutputPath
+    // but we'll clear them out periodically while the app isn't started
+    std::thread aTraceReadThread(readATraceThread);
+
+    cout << "Waiting for process to start..." << endl;
+
+    while (pid == "")
     {
-        auto duration = printPerformanceMeasure(pid);
-        std::this_thread::sleep_for(std::chrono::milliseconds(interval - duration));
+        clearATraceLines();
+        pid = pidOf(bundleId);
+        std::this_thread::sleep_for(std::chrono::milliseconds(50));
     }
+
+    try
+    {
+        while (true)
+        {
+            auto duration = printPerformanceMeasure(pid);
+            std::this_thread::sleep_for(std::chrono::milliseconds(interval - duration));
+        }
+    }
+    catch (const PidClosedError &e)
+    {
+        cerr << "CPP_ERROR_MAIN_PID_CLOSED " + pid << endl;
+        pollPerformanceMeasures(bundleId, interval);
+        return;
+    }
+
+    aTraceReadThread.join();
 }
 
 void printCpuClockTick()
@@ -105,12 +151,6 @@ void printRAMPageSize()
     cout << sysconf(_SC_PAGESIZE) << endl;
 }
 
-std::string pidOf(string bundleId)
-{
-    auto result = executeCommand("pidof " + bundleId);
-    return result.substr(0, result.find_first_of("\n"));
-}
-
 int main(int argc, char **argv)
 {
     string methodName = argv[1];
@@ -119,24 +159,8 @@ int main(int argc, char **argv)
     {
         string bundleId = argv[2];
         int interval = std::stoi(argv[3]);
-        string pid = "";
-
-        // We read atrace lines before the app is started
-        // since it can take a bit of time to start and clear the traceOutputPath
-        // but we'll clear them out periodically while the app isn't started
-        std::thread aTraceReadThread(readATraceThread);
-
-        cout << "Waiting for process to start..." << endl;
-
-        while (pid == "")
-        {
-            clearATraceLines();
-            pid = pidOf(bundleId);
-            std::this_thread::sleep_for(std::chrono::milliseconds(50));
-        }
 
-        pollPerformanceMeasures(pid, interval);
-        aTraceReadThread.join();
+        pollPerformanceMeasures(bundleId, interval);
     }
     else if (methodName == "printPerformanceMeasure")
     {

packages/android-performance-profiler/src/commands/__tests__/cppProfiler.test.ts

@@ -16,6 +16,11 @@ on multiple lines`;
 
   expect(
     parseCppMeasure(`=START MEASURE=
+ANOTHER_PID
+=SEPARATOR=
+Beginning of CPU info but wait we're restarting
+Waiting for process start...
+=START MEASURE=
 ${PID}
 =SEPARATOR=
 ${CPU}

packages/android-performance-profiler/src/commands/cppProfiler.ts

@@ -115,10 +115,10 @@ export const parseCppMeasure = (measure: string): CppPerformanceMeasure => {
   const DELIMITER = "=SEPARATOR=";
   const START_MEASURE_DELIMITER = "=START MEASURE=";
 
-  const [pid, cpu, ram, atrace, timings] = measure
-    .replace(START_MEASURE_DELIMITER, "")
-    .split(DELIMITER)
-    .map((s) => s.trim());
+  const measureSplit = measure.split(START_MEASURE_DELIMITER);
+  const measureContent = measureSplit[measureSplit.length - 1];
+
+  const [pid, cpu, ram, atrace, timings] = measureContent.split(DELIMITER).map((s) => s.trim());
 
   const [timestampLine, execTimings] = timings.split(/\r\n|\n|\r/);
 
@@ -131,7 +131,8 @@ export const parseCppMeasure = (measure: string): CppPerformanceMeasure => {
 
 export const pollPerformanceMeasures = (
   pid: string,
-  onData: (measure: CppPerformanceMeasure) => void
+  onData: (measure: CppPerformanceMeasure) => void,
+  onPidChanged?: (pid: string) => void
 ) => {
   ensureCppProfilerIsInstalled();
 
@@ -145,9 +146,22 @@ export const pollPerformanceMeasures = (
     }
   );
 
+  process.stderr?.on("data", (data) => {
+    const log = data.toString();
+
+    // Ignore errors, it might be that the thread is dead and we can't read stats anymore
+    if (log.includes("CPP_ERROR_CANNOT_OPEN_FILE")) {
+      Logger.debug(log);
+    } else if (log.includes("CPP_ERROR_MAIN_PID_CLOSED")) {
+      onPidChanged?.(pid);
+    } else {
+      Logger.error(log);
+    }
+  });
+
   return {
     stop: () => {
-      process.stop();
+      process.kill();
       // We need to close this process, otherwise tests will hang
       Logger.debug("Stopping atrace process...");
       stopATrace();

packages/android-performance-profiler/src/commands/cpu/getCpuStatsByProcess.ts

@@ -1,5 +1,3 @@
-import { Logger } from "@perf-profiler/logger";
-
 export interface ProcessStat {
   processId: string;
   processName: string;
@@ -11,14 +9,6 @@ export const processOutput = (output: string, pid: string): ProcessStat[] =>
   output
     .split(/\r\n|\n|\r/)
     .filter(Boolean)
-    .filter((line) => {
-      // Ignore errors, it might be that the thread is dead and we can read stats anymore
-      if (line.includes("C++ Error")) {
-        Logger.debug(line);
-        return false;
-      }
-      return true;
-    })
     .map((stats) => stats.split(" "))
     .filter(Boolean)
     .map((subProcessStats) => {

packages/android-performance-profiler/src/commands/pollPerformanceMeasures.ts

@@ -21,47 +21,61 @@ export const pollPerformanceMeasures = (
   let initialTime: number | null = null;
   let previousTime: number | null = null;
 
-  const cpuMeasuresAggregator = new CpuMeasureAggregator();
-  const frameTimeParser = new FrameTimeParser();
+  let cpuMeasuresAggregator = new CpuMeasureAggregator();
+  let frameTimeParser = new FrameTimeParser();
 
-  return cppPollPerformanceMeasures(bundleId, ({ pid, cpu, ram: ramStr, atrace, timestamp }) => {
-    if (!atrace) {
-      Logger.debug("NO ATRACE OUTPUT, if the app is idle, that is normal");
-    }
-    const subProcessesStats = processOutput(cpu, pid);
+  const reset = () => {
+    initialTime = null;
+    previousTime = null;
+    cpuMeasuresAggregator = new CpuMeasureAggregator();
+    frameTimeParser = new FrameTimeParser();
+  };
 
-    const ram = processRamOutput(ramStr);
-    const { frameTimes, interval: atraceInterval } = frameTimeParser.getFrameTimes(atrace, pid);
+  return cppPollPerformanceMeasures(
+    bundleId,
+    ({ pid, cpu, ram: ramStr, atrace, timestamp }) => {
+      if (!atrace) {
+        Logger.debug("NO ATRACE OUTPUT, if the app is idle, that is normal");
+      }
+      const subProcessesStats = processOutput(cpu, pid);
 
-    if (!initialTime) {
-      initialTime = timestamp;
-    }
+      const ram = processRamOutput(ramStr);
+      const { frameTimes, interval: atraceInterval } = frameTimeParser.getFrameTimes(atrace, pid);
 
-    if (previousTime) {
-      const interval = timestamp - previousTime;
+      if (!initialTime) {
+        initialTime = timestamp;
+      }
 
-      const cpuMeasures = cpuMeasuresAggregator.process(subProcessesStats, interval);
+      if (previousTime) {
+        const interval = timestamp - previousTime;
 
-      const fps = FrameTimeParser.getFps(
-        frameTimes,
-        atraceInterval,
-        Math.max(
-          cpuMeasures.perName["UI Thread"] || 0,
-          // Hack for Flutter apps - if this thread is heavy app will be laggy
-          cpuMeasures.perName["(1.ui)"] || 0
-        )
-      );
+        const cpuMeasures = cpuMeasuresAggregator.process(subProcessesStats, interval);
 
-      onMeasure({
-        cpu: cpuMeasures,
-        fps,
-        ram,
-        time: timestamp - initialTime,
-      });
-    } else {
-      onStartMeasuring();
-      cpuMeasuresAggregator.initStats(subProcessesStats);
+        const fps = FrameTimeParser.getFps(
+          frameTimes,
+          atraceInterval,
+          Math.max(
+            cpuMeasures.perName["UI Thread"] || 0,
+            // Hack for Flutter apps - if this thread is heavy app will be laggy
+            cpuMeasures.perName["(1.ui)"] || 0
+          )
+        );
+
+        onMeasure({
+          cpu: cpuMeasures,
+          fps,
+          ram,
+          time: timestamp - initialTime,
+        });
+      } else {
+        onStartMeasuring();
+        cpuMeasuresAggregator.initStats(subProcessesStats);
+      }
+      previousTime = timestamp;
+    },
+    () => {
+      Logger.warn("Process id has changed, ignoring measures until now");
+      reset();
     }
-    previousTime = timestamp;
-  });
+  );
 };

packages/android-performance-profiler/src/commands/shell.ts

@@ -33,7 +33,14 @@ if (!global.Flipper) {
   process.on("SIGTERM", exit); // `kill` command
 }
 
-export const executeAsync = (command: string): ChildProcess => {
+class AsyncExecutionError extends Error {}
+
+export const executeAsync = (
+  command: string,
+  { logStderr } = {
+    logStderr: true,
+  }
+): ChildProcess => {
   const parts = command.split(" ");
 
   const childProcess = spawn(parts[0], parts.slice(1));
@@ -43,11 +50,22 @@ export const executeAsync = (command: string): ChildProcess => {
   });
 
   childProcess.stderr?.on("data", (data) => {
-    Logger.error(`Process for ${command} errored with ${data.toString()}`);
+    if (logStderr) Logger.error(`Process for ${command} errored with ${data.toString()}`);
   });
 
   childProcess.on("close", (code) => {
     Logger.debug(`child process exited with code ${code}`);
+
+    const AUTHORIZED_CODES = [
+      0, // Success
+      140, // SIGKILL
+      143, // SIGTERM
+    ];
+
+    // SIGKILL or SIGTERM are likely to be normal, since we request termination from JS side
+    if (code && !AUTHORIZED_CODES.includes(code)) {
+      throw new AsyncExecutionError(`Process for ${command} exited with code ${code}`);
+    }
   });
 
   childProcess.on("error", (err) => {
@@ -64,7 +82,9 @@ export const executeLongRunningProcess = (
   delimiter: string,
   onData: (data: string) => void
 ) => {
-  const process = executeAsync(command);
+  const process = executeAsync(command, {
+    logStderr: false,
+  });
   let currentChunk = "";
 
   process.stdout?.on("data", (data: ReadableStream<string>) => {
@@ -83,9 +103,5 @@ export const executeLongRunningProcess = (
     }
   });
 
-  return {
-    stop: () => {
-      process.kill();
-    },
-  };
+  return process;
 };

packages/e2e-performance/src/PerformanceMeasurer.ts

@@ -31,6 +31,7 @@ export class PerformanceMeasurer {
         Logger.debug(`Received measure ${this.measures.length}`);
       },
       onStartMeasuring: () => {
+        this.measures = [];
         this.timingTrace = new Trace();
       },
     });