Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Merged
merged 13 commits into from
Jul 12, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -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
```
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
2 changes: 1 addition & 1 deletion packages/android-performance-profiler/cpp-profiler/run.sh
Original file line number Diff line number Diff line change
Expand Up @@ -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
80 changes: 52 additions & 28 deletions packages/android-performance-profiler/cpp-profiler/src/main.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@
#include <unistd.h>
#include "utils.h"

using std::cerr;
using std::cout;
using std::endl;
using std::string;
Expand All @@ -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";
Expand Down Expand Up @@ -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()
Expand All @@ -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];
Expand All @@ -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")
{
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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}
Expand Down
26 changes: 20 additions & 6 deletions packages/android-performance-profiler/src/commands/cppProfiler.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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/);

Expand All @@ -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();

Expand All @@ -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();
Expand Down
Original file line number Diff line number Diff line change
@@ -1,5 +1,3 @@
import { Logger } from "@perf-profiler/logger";

export interface ProcessStat {
processId: string;
processName: string;
Expand All @@ -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) => {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
});
);
};
32 changes: 24 additions & 8 deletions packages/android-performance-profiler/src/commands/shell.ts
Original file line number Diff line number Diff line change
Expand Up @@ -4,7 +4,7 @@
export const executeCommand = (command: string): string => {
try {
return execSync(command, { stdio: "pipe" }).toString();
} catch (error: any) {

Check warning on line 7 in packages/android-performance-profiler/src/commands/shell.ts

View workflow job for this annotation

GitHub Actions / tests

Unexpected any. Specify a different type
Logger.debug(`Error while executing command "${command}": ${error.stderr.toString()}`);
throw error;
}
Expand Down Expand Up @@ -33,7 +33,14 @@
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));
Expand All @@ -43,11 +50,22 @@
});

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()}`);
niebo26 marked this conversation as resolved.
Show resolved Hide resolved
});

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) => {
Expand All @@ -64,7 +82,9 @@
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>) => {
Expand All @@ -83,9 +103,5 @@
}
});

return {
stop: () => {
process.kill();
},
};
return process;
};
1 change: 1 addition & 0 deletions packages/e2e-performance/src/PerformanceMeasurer.ts
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,7 @@ export class PerformanceMeasurer {
Logger.debug(`Received measure ${this.measures.length}`);
},
onStartMeasuring: () => {
this.measures = [];
this.timingTrace = new Trace();
},
});
Expand Down
Loading
Loading