swung0x48/MobileGL
1
0
Fork 0
mirror of https://github.com/MobileGL-Dev/MobileGL synced 2026-11-07 01:53:24 +09:00
Code Issues Packages Projects Releases Wiki Activity

[MG_Util, MG_Remote, tools] (P6): the wire counters and the spawn server's stats latch

Browse Source 
Gate 8's last two numbers (SEG_STAGE bytes/frame, records/frame post-
chunking) had no producer at all: the summary line's byte classes are
backend-to-driver bytes and maxrec is a max, not a per-frame. Two push-
guarded counters answer them at their single choke points - ByteClass::
StageSegmentBytes at PipeWireCodec's StageAllocate (the only allocation
behind StageBytes, so every buffer walk, texture slab and CSO archive
lands there and emitters cannot double-count) and CallClass::WireRecords
on EncodeRecord's committed path (post-chunking an emitter no longer
knows how many records its one call produced). A staged-blob histogram
rides along. G1 holds: symbols 0/0/0/0, .text byte-identical, pull build
carries no MG_Remote symbols.

The spawn server never counted anything: PipeStats::Init() is a step of
MobileGL::Initialize(), which ServerMain never reaches, so every Enabled()
site in that process - including ServerLoop's own ServerWaits/ServerParks
publish - stayed false and the server log carried no summary line at all
(a zero that means 'another process' printed in the shape of one that
means 'never waited' is the milder misreading; the line was simply
absent). ServerMain now arms and closes PipeStats at its role boundary -
after MG_ConfigLoader::Init (Init latches from the parsed config), after
the server-role latch (the log sink's role), and before ::_exit(0).
Red-once: 0 server summary lines before, 29 after, SSIM 1.0 unchanged.

MOBILEGL_PIPE_STATS_FILE now derives per role through the log sink's
exported RoleLogPath rule - run.client.json / run.server.json, the bare
name resolves to no file - because both roles reach FormatJson() and ofstream
trunc made the second writer replace the first. G1 caught three separate
leaks on the way (a string temporary in the monolith body, one resized
Shutdown() from unequal #if arms, two rewritten MGLOG_W literals in
.rodata); the pull arm is statement-for-statement the original.

Device tooling for the paired A/B lands with it: pin_device.sh gains a
measured 2f7cbe2e entry (this board clamps the GPU at 1050 MHz -
thermal_pwrlevel writes 0 and reads back 1, max_gpuclk is read-only;
absolute times are not comparable with the 1100 MHz-era rows), and
tools/device_bench/p6/ carries the session collector and renderer beside
run_android_retrace_local.py's MOBILEGL_TRACE_PACKAGE override.

Unit 2367/2367 (PipeStats 25/25), spawn integration 102/102.
This commit is contained in:
swung0x48
2026-09-22 03:37:51 -04:00
parent 4e7bf0fe65
commit 06b61bd84e
12 changed files with 2049 additions and 5 deletions
Download Patch File Download Diff File Expand all files Collapse all files
MobileGL/MG_Remote/Server/ServerMain.cpp
+50
View File
@@ -46,6 +46,7 @@
#include <Config.h> // MG_Config::Transport - D1 pins it to Spawn in this process
#include <MG_Backend/MGPipe/PipeInputs.h> // D1c: MGPipeSetServerProcessRole
#include <MG_Backend/ServerRole.h>
#include <MG_Util/Metrics/PipeStats.h> // step 1.6: the counters' latch, server-process half
#include <Init.h> // MG_ConfigLoader::Init - the child loads its own config (step 1.5)
#include <cstdio>
@@ -188,6 +189,46 @@ extern "C" __attribute__((visibility("default"))) int mobilegl_server_main(int a
// them; without it they are compiled in and permanently false, which is worse than absent
// because it reads as coverage.
MobileGL::MG_Pipe::MGPipeSetServerProcessRole(true);
// ---- 1.6. THE MGPIPE COUNTERS, and this is the ONLY call site outside
// MobileGL::Initialize().
//
// GATE 8'S SERVER HALF WAS STRUCTURALLY ZERO WITHOUT THIS, and the shape of the
// defect is worth stating: the child never runs MobileGL::Initialize, so
// PipeStats::Init() - a step of it - never ran here, and g_pipeStatsEnabled
// stayed false. Every one of the ~80 `if (Enabled())` sites in the backends and
// in MG_Remote (ServerLoop's own ServerWaits/ServerParks publish included)
// compiled in and was permanently false in this process. The contract's
// mandatory "socket doorbell vs inproc condvar" number therefore had no server
// half under `spawn` at all, and its absence read exactly like a real zero:
// `wait[srv=0 srvpark=0]` is what "the server never waited" looks like too.
//
// IT GOES AFTER THE CONFIG LOAD AND AFTER THE ROLE IS STATED, and both halves
// of that order are load-bearing:
//
// * AFTER MG_ConfigLoader::Init, because Init() LATCHES the flag out of
// MG_Config::Features.PipeStats, and the parser does not exist until the
// line above has run. Calling it earlier would latch the static default
// (false) and the MOBILEGL_PIPE_STATS the launcher passed would be read by
// nobody - the same class of defect the config load itself used to have.
// * AFTER MGPipeSetServerProcessRole, because that is what makes the LOG SINK
// know this process is the server, and PipeStats' summary line is emitted
// through MGLOG_I. The sink resolves its role from MOBILEGL_IPC_ROLE (which
// the launcher sets and its envp scrub preserves) and would in fact be
// right either way, but ordering it this way means the line cannot be filed
// under the client by a future change to that resolution. What the contract
// requires - that the summary lands in `<base>.server.log` - is asserted by
// the lane, not assumed from this comment.
//
// MOBILEGL_PIPE_STATS / _PERIOD / _FILE MEAN EXACTLY WHAT THEY MEAN IN THE
// CLIENT PROCESS, and that is the whole point of routing through Init(): all
// three are read from the child's own environment by the same parser and
// latched by the same function. Nothing about the stats channel is spawn-shaped.
// One asymmetry is real and intended: this process has no backend Present of
// its own, so its line cadence rides the present RECORDS it applies
// (PipeApplier -> DirectGLES/DirectVulkan Present -> OnPresent) rather than a
// swap the server does not perform. A spawn session that presents N times
// produces N windows here, which is the same N the client's own line counts.
MobileGL::MG_Util::PipeStats::Init();
WireLogError("MG_Remote server: pid=%d config loaded, backend=%d, Transport pinned to Spawn "
"(D1: this process IS the server arm)",
selfPid, static_cast<int>(MobileGL::MG_Config::ActiveBackendType));
@@ -390,6 +431,15 @@ extern "C" __attribute__((visibility("default"))) int mobilegl_server_main(int a
loop.Stop();
session.Close();
control->Shutdown();
// Step 1.6's other half, and its position is the same argument MobileGL::Destroy
// makes: AFTER loop.Stop(), because the apply thread is what publishes
// ServerWaits / ServerParks and a dump taken while it still runs is a race; and
// BEFORE _exit, because _exit runs no atexit handler and this is the only place
// the server's run totals and its JSON dump can be written at all. Without it
// the server printed whatever windows its last period boundary happened to
// reach and lost the final one - the same "the last frame's numbers can be
// lost" case Init.cpp's Shutdown call exists to avoid on the client side.
MobileGL::MG_Util::PipeStats::Shutdown();
std::fflush(nullptr);
::_exit(0);
}
MobileGL/MG_Remote/Wire/PipeWireCodec.cpp
+36
View File
@@ -38,6 +38,10 @@
#include <MG_Remote/Protocol/generated/protocol_generated.h>
#include <MG_State/GLState/ProgramState/ProgramArtifactsCodec.h>
#include <MG_Util/Debug/Log.h>
// P6 gate 8's two wire counters. MG_Util is BELOW MG_Remote in the build order and the pull build
// has no MG_Remote at all, which is why every counter this file touches is behind
// #if MOBILEGL_PIPE_PUSH - the same guard the header's producer readings live under.
#include <MG_Util/Metrics/PipeStats.h>
#include <cstdlib>
#include <cstring>
@@ -857,6 +861,24 @@ namespace MobileGL::MG_Remote::Wire {
static_cast<unsigned long long>(m_stageCapacity));
}
// P6 GATE 8's FIRST NUMBER (CONTRACT-P6.md §9 item 8): the bytes this producer staged. The
// blob's OWN bytes are recorded, from here - where the request first becomes an allocation
// - because this is the ONE place every writer of SEG_STAGE passes through (StageBytes is
// the only caller, and every buffer walk, texture slab, CSO archive and block name reaches
// them through it), which is what makes the count complete by construction rather than by
// a hand-kept list of callers.
//
// `size`, NOT `need`: the Align8 slack is the allocator's, not content the producer wrote,
// and charging it here would make a workload of 8-byte blobs look like one of 16-byte
// blobs. The allocator's wrap skip is excluded for the same reason.
//
// The sample below the byte add is the same call site for the same reason: the per-blob
// distribution is a property of what the PRODUCER handed over, before the arena rounds it.
if (MG_Util::PipeStats::Enabled()) {
MG_Util::PipeStats::AddBytes(MG_Util::PipeStats::ByteClass::StageSegmentBytes, size);
MG_Util::PipeStats::RecordStagedBlobBytes(size);
}
bool reclaimed = false;
bool waited = false;
for (;;) {
@@ -1152,6 +1174,20 @@ namespace MobileGL::MG_Remote::Wire {
// the measured answer on the reduced path is a different row entirely.
m_maxRecordOp = op;
}
// P6 GATE 8's SECOND NUMBER (CONTRACT-P6.md §9 item 8), and it is counted HERE rather than
// at any emitter for the reason the CallClass comment gives: after chunking, the emitter
// no longer knows how many records its one call produced. By this point the record is
// COMMITTED - Reserve succeeded, the body is written and the blob slots have been checked
// honest - so this is exactly "records/frame post-chunking", not "emitter calls/frame".
//
// A kRecPad FILLER CANNOT REACH HERE: Reserve returns the filler's wake-up as a refusal
// (kInvalidSeq) and the caller retries, so no pad is ever counted, which is what keeps
// this number comparable with the seq space R-3 defines. A REFUSED emission is not counted
// either - the early return above is what makes one record cost exactly one.
if (MG_Util::PipeStats::Enabled()) {
MG_Util::PipeStats::AddCalls(MG_Util::PipeStats::CallClass::WireRecords, 1);
}
++m_emitSeq;
// The stage mark: where SEG_STAGE stood once everything this record names had been
// staged. ReclaimStagedBytes releases up to the newest mark the server has retired.
MobileGL/MG_Test/Util/PipeStatsTest.cpp
+225
View File
@@ -13,6 +13,7 @@
#include <gtest/gtest.h>
#include <Config.h>
#include <MG_Util/Debug/Log.h>
#include <MG_Util/Metrics/PipeStats.h>
#include <cstdio>
@@ -93,6 +94,109 @@ namespace {
PS::Init();
}
// THE LATCH IS THE WHOLE CONTRACT, and this case exists because a spawn server got
// it wrong in a way no other test could see. `Init()` is a step of
// MobileGL::Initialize(), and the spawn server process never calls that - it calls
// MG_ConfigLoader::Init + InitServerRoleForSpawn - so `g_pipeStatsEnabled` stayed
// false there and every `if (Enabled())` site in the process was permanently
// false. The observable consequence was not a wrong number but an ABSENT one:
// the server printed no summary line at all, and `wait[srv=0 srvpark=0]` (what a
// reader would have taken for "the server never waited") is in fact what this
// case's "false" arm looks like.
//
// It pins both directions, because only the pair is falsifiable: Init() must TAKE
// the config's value when it is true, and must CLEAR the latch when it is false -
// a version that only ever set the flag true would pass a one-sided test while
// making MOBILEGL_PIPE_STATS=0 mean nothing in a long-lived process.
TEST_F(PipeStatsTest, InitIsTheOnlyLatchAndItTakesTheConfigBothWays) {
const bool saved = MobileGL::MG_Config::Features.PipeStats;
MobileGL::MG_Config::Features.PipeStats = true;
PS::Init();
EXPECT_TRUE(PS::Enabled()) << "a true config must arm the counters";
MobileGL::MG_Config::Features.PipeStats = false;
PS::Init();
EXPECT_FALSE(PS::Enabled()) << "and a false one must disarm them, not leave the old latch";
MobileGL::MG_Config::Features.PipeStats = saved;
PS::Init();
}
// A summary line is emitted by whichever role reaches OnPresent, and this is what makes
// the spawn server's line appear at all: it has no swap of its own, so its cadence
// rides the present records it applies. The assertion is the arithmetic that cadence
// rests on - k presentations produce k windows when the period is 1 - because that is
// the property the lane's per-frame rates divide by.
TEST_F(PipeStatsTest, PresentationsAtTheDefaultPeriodOfOneMakeOneWindowEach) {
const Uint32 saved = MobileGL::MG_Config::Features.PipeStatsPeriod;
MobileGL::MG_Config::Features.PipeStatsPeriod = 1;
PS::Init();
for (Uint32 i = 0; i < 5; ++i) {
PS::PublishGauge(PS::Gauge::ServerWaits, static_cast<Uint64>(100 * (i + 1)));
PS::OnPresent();
}
EXPECT_EQ(PS::FrameCount(), 5u);
// The gauge is a RUN TOTAL: publishing five increasing values leaves the last one,
// never their sum. This is the mistake the report's first aggregation script made.
EXPECT_EQ(PS::GaugeValue(PS::Gauge::ServerWaits), 500u);
MobileGL::MG_Config::Features.PipeStatsPeriod = saved;
PS::Init();
}
// P6 gate 8: THE DUMP PATH IS ROLE-DERIVED AND THE BASE NAME IS NOT A FILE.
//
// The trap this exists for: under `spawn` both roles reach PipeStats::Shutdown() (the client
// through MobileGL::Destroy, the server through ServerMain's own call), and before this both
// opened MOBILEGL_PIPE_STATS_FILE itself with trunc - so the second writer silently replaced
// the first, and a reader held one role's numbers under a name that claimed to be the run's.
//
// ---- WHAT THIS CASE ASSERTS, AND WHAT ITS FIRST VERSION GOT WRONG ----
//
// The first version asserted about MG_Util::Debug::RoleLogPath directly: that the two roles get
// different paths, that neither equals the base name. All of that PASSED WITH THE FIX REVERTED -
// it tested the naming helper, which was never broken. What was broken was that the dump did
// not CALL it. A test that stays green while the defect is present is worse than no test.
//
// So the subject here is RoleDerivedJsonDumpPathForTesting(), the same expression the dump and
// the banner use; and the third assertion is the negative control the design rests on - the
// base name must not exist as a file, so a reader that was not updated gets ENOENT and says so
// rather than a file that looks like a complete run and is half of one.
TEST_F(PipeStatsTest, JsonDumpPathIsRoleDerivedAndTheBaseNameIsNeverOpened) {
using MobileGL::MG_Util::Debug::LogRole;
const String saved = MobileGL::MG_Config::Features.PipeStatsFile;
const char* base = "/tmp/mobilegl-pipestats-role-test.json";
// Unset: no path at all, and specifically not the empty string spelled as a file name.
MobileGL::MG_Config::Features.PipeStatsFile = "";
EXPECT_TRUE(PS::RoleDerivedJsonDumpPathForTesting().empty());
MobileGL::MG_Config::Features.PipeStatsFile = base;
const String path = PS::RoleDerivedJsonDumpPathForTesting();
// (1) THE DUMP PATH IS THE DERIVED ONE, spelled out, so a change to the rule is a change
// to this test. A unit process is the client role.
EXPECT_EQ(path, String("/tmp/mobilegl-pipestats-role-test.client.json"));
// (2) THE BASE NAME IS NOT THE PATH. This is the collision itself: if the dump wrote the
// configured name, spawn's second writer would truncate the first.
EXPECT_NE(path, String(base));
// (3) THE NEGATIVE CONTROL. PipeStats writes the derived path, never the base, so nothing
// may have created the base. A fresh base is absent, and this fails if that ever stops
// being true - which is exactly what a revert of the derivation does.
std::remove(base);
std::ifstream baseFile(base);
EXPECT_FALSE(baseFile.good())
<< "the configured base name exists; something opened it directly, and under spawn "
"that is the trunc-versus-trunc collision this derivation exists to prevent";
MobileGL::MG_Config::Features.PipeStatsFile = saved;
}
TEST_F(PipeStatsTest, GateHitsAndMissesAreSeparateCounters) {
for (Uint32 i = 0; i < 5; ++i) {
PS::CountGate(PS::Gate::MagmaPipelineMemo, /*hit=*/true);
@@ -171,6 +275,15 @@ namespace {
// And the new ByteClass rides the ordinary bytes[] bracket under a short name that is
// NOT "csob": the cso[] bracket above already prints csob= for the CSO bind count.
EXPECT_NE(line.find("csob-blob="), String::npos) << line;
// P6 GATE 8'S TWO NUMBERS (CONTRACT-P6.md §9 item 8), pinned where an operator's grep
// would break. `seg` is the ByteClass that says how many bytes a frame stages into
// SEG_STAGE, and `wrec` / `wrec/f` are the post-chunking record count and its per-frame
// figure. The short name is `seg` and not `stage`, which would read as a prefix of
// `stage-buffer`'s long name and of nothing else in the bracket; it is also not `ssb`,
// because this is a per-frame BYTES field and `ssb` reads like a count.
EXPECT_NE(line.find("seg="), String::npos) << line;
EXPECT_NE(line.find("wrec="), String::npos) << line;
EXPECT_NE(line.find("wrec/f="), String::npos) << line;
// P5d round 3's wait ledger. Four fields on a bracket of their own, and they are
// pinned here for the reason every other short name is: they are what the inproc
// performance work reads out of a run's log, so a rename or a dropped field breaks
@@ -197,6 +310,114 @@ namespace {
EXPECT_NE(line.find("buf=97.14"), String::npos) << line;
}
#if MOBILEGL_PIPE_PUSH
// P6 GATE 8's TWO NUMBERS (CONTRACT-P6.md §9 item 8), and each half is pinned because each
// half is a way the deliverable can be wrong without looking wrong.
//
// `seg` IS THE PRODUCER'S OWN BYTES. The wire encoder adds `size` and not the allocator's
// Align8 of it (PipeWireCodec.cpp's StageAllocate), so a blob of 4096 stages 4096. Checked
// here on the module's own arithmetic because that is the only place the rule can be read
// without a live ring: the encoder's call site is deliberately one line and has no test of
// its own.
TEST_F(PipeStatsTest, StageSegmentBytesIsAWindowedByteClassLikeAnyOther) {
PS::AddBytes(PS::ByteClass::StageSegmentBytes, 4096);
PS::AddBytes(PS::ByteClass::StageSegmentBytes, 2048);
PS::AddCalls(PS::CallClass::Draws, 1);
PS::OnPresent();
EXPECT_EQ(PS::TotalBytes(PS::ByteClass::StageSegmentBytes), 6144u);
EXPECT_EQ(PS::FrameBytes(PS::ByteClass::StageSegmentBytes), 0u) << "a Present clears the frame";
// 6144 over one frame, two decimals, in the ordinary bytes[] bracket.
EXPECT_NE(PS::FormatWindowLine().find("seg=6144.00"), String::npos)
<< PS::FormatWindowLine();
PS::AdvanceSummaryWindow();
// And it obeys the file's LABEL rule, not a rule of its own: the new window has no
// Present in it, so the bracket is relabelled "bytes[" and `seg` carries the window
// TOTAL verbatim rather than a figure divided by a faked frame count. That is the same
// rule the bytes[] bracket follows and the same one the two window-total tests below
// pin; asserting "seg=0.00" here is what the first cut of this case did, and it was
// asserting a per-frame form the line deliberately does not print.
const String empty = PS::FormatWindowLine();
EXPECT_NE(empty.find("bytes["), String::npos) << empty;
EXPECT_EQ(empty.find("bytes/f["), String::npos) << empty;
EXPECT_NE(empty.find("seg=0"), String::npos) << empty;
}
// `wrec` IS A COUNT, SO IT DOES NOT DIVIDE LIKE A BYTE CLASS - and the per-frame form must
// read off the line, which is why the field exists at all rather than the operator doing the
// division by hand. 26 records over 13 frames is 2.00; the window total is printed beside it
// so the pair is self-checking.
TEST_F(PipeStatsTest, WireRecordsCarryBothTheWindowCountAndItsPerFrameForm) {
PS::AddCalls(PS::CallClass::WireRecords, 26);
for (Uint32 i = 0; i < 13; ++i) {
PS::OnPresent();
}
const String line = PS::FormatWindowLine();
EXPECT_NE(line.find("wrec=26"), String::npos) << line;
EXPECT_NE(line.find("wrec/f=2.00"), String::npos) << line;
}
// AND THE LABEL RULE THE FILE ALREADY OWNS APPLIES TO IT: a window with no Present in it has
// no per-frame reading, so `wrec/f` carries the window total rather than a figure divided by
// a faked 1. This is the same 47x overstatement PipeStatsTest pins for the bytes[] bracket,
// one field over, and it is the shape a trace slice with no swap at all would hit.
TEST_F(PipeStatsTest, WireRecordsFallBackToTheWindowTotalWithoutAFrame) {
PS::AddCalls(PS::CallClass::WireRecords, 47);
const String line = PS::FormatWindowLine();
EXPECT_EQ(PS::FrameCount(), 0u);
EXPECT_NE(line.find("wrec=47"), String::npos) << line;
EXPECT_NE(line.find("wrec/f=47"), String::npos) << line;
EXPECT_EQ(line.find("wrec/f=47.00"), String::npos) << line;
}
// THE STAGED-BLOB DISTRIBUTION, which is the optional deliverable MEASUREMENTS.md:342 says
// has never existed. It shares the draw-payload histogram's edges - bucket 0 is "0 bytes",
// bucket n>0 is [2^(n-1), 2^n) - so the two are read the same way, and it is a COUNT per
// bucket rather than a byte sum: the shape is the deliverable and the bytes have their own
// counter in `seg`.
TEST_F(PipeStatsTest, StagedBlobHistogramSharesThePayloadBucketEdges) {
PS::RecordStagedBlobBytes(1); // [1, 2) -> bucket 1
PS::RecordStagedBlobBytes(4096); // [4096,8192)-> bucket 13
PS::RecordStagedBlobBytes(4096); // same bucket
PS::RecordStagedBlobBytes(8192); // [8192,...) -> bucket 14: the edge is exclusive
EXPECT_EQ(PS::TotalStagedBlobBucket(1), 1u);
EXPECT_EQ(PS::TotalStagedBlobBucket(13), 2u);
EXPECT_EQ(PS::TotalStagedBlobBucket(14), 1u);
EXPECT_EQ(PS::TotalStagedBlobBucket(0), 0u);
// Saturation and the out-of-range read, exactly as the draw-payload histogram's.
PS::RecordStagedBlobBytes(~Uint64{0});
EXPECT_EQ(PS::TotalStagedBlobBucket(PS::kStagedBlobHistogramBuckets - 1), 1u);
EXPECT_EQ(PS::TotalStagedBlobBucket(PS::kStagedBlobHistogramBuckets), 0u);
}
// A distribution is a RUN TOTAL and has no business being windowed: it is a shape over the
// whole workload, and a Present that cleared it would report the shape of one frame as if it
// were the run's. It reaches an operator through the JSON dump - the same channel and for the
// same reason the draw-payload histogram uses it - so that is where it is asserted.
TEST_F(PipeStatsTest, StagedBlobHistogramIsARunTotalAndReachesTheJsonDump) {
PS::RecordStagedBlobBytes(1024);
PS::OnPresent();
const String json = PS::FormatJson();
EXPECT_NE(json.find("\"staged-blob-bytes-histogram\""), String::npos) << json;
EXPECT_NE(json.find("\"wire-records\""), String::npos) << json;
EXPECT_NE(json.find("\"stage-segment-bytes\""), String::npos) << json;
// Run total, not a window: the sample above survives the Present.
EXPECT_EQ(PS::TotalStagedBlobBucket(11), 1u);
// The ordering is the JSON document's shape, not decoration: the new array is a SIBLING
// of the draw-payload one, so a reader that walks the object finds both where the two
// comments say they are.
EXPECT_LT(json.find("\"cmd-bytes-per-draw-histogram\""),
json.find("\"staged-blob-bytes-histogram\""))
<< json;
}
#endif
// Successive summaries report WINDOWS, not run totals: a run total over a workload that
// changes shape (load, then steady state) averages away the very number section 2.3.1
// wants. Advancing the window is an explicit call, not a side effect of formatting.
@@ -312,6 +533,10 @@ namespace {
EXPECT_STREQ(PS::NameOf(PS::CallClass::ClientTextureUploadEmissions),
"client-tex-upload-emissions");
EXPECT_STREQ(PS::NameOf(PS::ByteClass::CsoBlobBytes), "cso-blob-bytes");
// P6 gate 8's two, under their long names - the JSON dump keys and the names the
// MEASUREMENTS.md entry will quote.
EXPECT_STREQ(PS::NameOf(PS::ByteClass::StageSegmentBytes), "stage-segment-bytes");
EXPECT_STREQ(PS::NameOf(PS::CallClass::WireRecords), "wire-records");
#endif
EXPECT_STREQ(PS::NameOf(PS::Gate::EsprytRenderState), "espryt-render-state");
EXPECT_STREQ(PS::NameOf(PS::Gate::EsprytTextureSyncList), "espryt-texture-sync-list");
MobileGL/MG_Util/Debug/Log.cpp
+11
View File
@@ -94,6 +94,17 @@ namespace MobileGL {
}
return path.substr(0, dot) + "." + roleSuffix + path.substr(dot);
}
// P6 gate 8: the role, in the two forms a caller can hold it in. Both are thin readers of
// state this file already keeps; neither adds a second source of truth.
LogRole CurrentThreadRole() {
if (t_logRole < 0) {
t_logRole = ProcessIsSpawnedServer() ? 1 : 0;
}
return t_logRole == 1 ? LogRole::Server : LogRole::Client;
}
bool CurrentProcessIsSpawnedServer() { return ProcessIsSpawnedServer(); }
#endif
std::mutex& LogMutex() {
MobileGL/MG_Util/Debug/Log.h
+25
View File
@@ -164,6 +164,24 @@ namespace MobileGL {
// "the library never logged", which reads as a product failure.
std::string RoleLogPath(const char* basePath, LogRole role);
// WHICH ROLE IS THE CALLING THREAD, exported for the same reason the naming rule is:
// a second answer to "am I the server" is a second answer that can disagree, and this
// one already exists twice inside this file (ThreadIsServerRole, ProcessIsSpawnedServer)
// in a form nothing outside can read.
//
// P6 GATE 8 NEEDS IT, and that is the caller that made it worth exporting. The MGPipe
// counters' JSON dump is written by whichever role reaches PipeStats::Shutdown(), and
// under `spawn` both roles do - in two processes, onto the same configured path. The
// fix is the log sink's own split (each role gets its own file), and the role is the
// only input that split needs.
LogRole CurrentThreadRole();
// The same question about a whole PROCESS rather than a thread: true only for a
// spawned server image, which is the server on every thread. Exported because the
// distinction matters to callers that are deciding a FILE NAME before any role has
// been stamped on a thread. `bool` rather than `Bool`: this header is included from
// translation units that do not pull MobileGL/Defines.h (Log.cpp is one of them).
bool CurrentProcessIsSpawnedServer();
// THE TWO OPERATIONS EVERY READER ACTUALLY WANTS, so that no caller has to know how
// many roles there are or how they are spelled.
//
@@ -197,6 +215,13 @@ namespace MobileGL {
return basePath == nullptr ? std::string() : std::string(basePath);
}
// INLINE, like everything else in this pull arm, and for the same G1 reason. There is
// one role in this build, so "which role is this thread" has exactly one true answer
// and no state to read - but a caller must still compile and mean the right thing in
// both flavours rather than wrapping these in an `#if` it might get wrong once.
inline LogRole CurrentThreadRole() { return LogRole::Client; }
inline bool CurrentProcessIsSpawnedServer() { return false; }
inline std::string ReadRoleLogs(const char* basePath) {
std::string all;
if (basePath == nullptr) return all;
MobileGL/MG_Util/Metrics/PipeStats.cpp
+158 -4
View File
@@ -9,6 +9,7 @@
#include "PipeStats.h"
#include <Config.h>
#include <MG_Util/Debug/Log.h>
#include <fstream>
@@ -93,10 +94,29 @@
// above. The two are different questions about the same bytes under
// split, and adding them is wrong.
// residual-value-block Placeholder, always 0 until P2 (plan section 6.3).
// stage-segment-bytes P6 gate 8, and the only class in this list that is neither a backend's
// copy nor a client's blob declaration: it counts what the WIRE put into
// SEG_STAGE. One site, PipeWireEncoder::StageAllocate, which is the single
// allocation call behind PipeWireEncoder::StageBytes - so every writer
// (the buffer content walks, the texture slabs, the CSO archives, the
// storage-block names) is covered by construction rather than by being on
// a list. Align8 slack and the allocator's wrap skip are real occupancy
// and are deliberately NOT counted; see the ByteClass comment. It is a
// per-frame average by construction, so the per-blob SHAPE - the thing
// that says whether the chunk budget is cutting where it should - is the
// staged-blob histogram in the JSON dump, not this number.
//
// Call classes
// draws DirectGLES PrepareForDraw and DirectVulkan SetupDraw's entry. A
// dispatch is not a draw and is not counted.
// wire-records P6 gate 8: one per record the wire encoder COMMITTED, on
// PipeWireEncoder::EncodeRecord's successful path. Post-chunking by
// construction - an application call whose content is cut at
// MGPipeStageChunkBytes() produces several. A kRecPad ring filler is not a
// record and is not counted; an emission Reserve refused is counted once,
// when the retry succeeds. The emitter-side Client*Emissions counters
// answer a different question and the two together are what show what the
// suppressors absorbed.
// accessor-calls STATIC TALLIES at the instrumented entry points, NOT a wrapper
// around all 293 pGLContext-> sites. Each instrumented function adds
// the number of GLContext accessor calls that its OWN body executed
@@ -144,6 +164,11 @@ namespace MobileGL::MG_Util::PipeStats {
Counter g_totalGateMiss[kGateCount];
Counter g_totalPayloadBuckets[kPayloadHistogramBuckets];
Counter g_frameCount{0};
#if MOBILEGL_PIPE_PUSH
// P6 gate 8's second histogram, and push-only for the same reason its accessor is: its
// only sampler is the wire encoder, which a pull build does not compile.
Counter g_totalStagedBlobBuckets[kStagedBlobHistogramBuckets];
#endif
// Window bases: the run totals as of the previous summary line. Only ever touched
// from OnPresent()/Shutdown() (the present thread), so plain integers.
@@ -201,7 +226,7 @@ namespace MobileGL::MG_Util::PipeStats {
"stage-ubo-named", "stage-vertex-client", "stage-index-client",
"stage-indirect-cmd", "persistent-map-push", "residual-value-block",
#if MOBILEGL_PIPE_PUSH
"cso-blob-bytes",
"cso-blob-bytes", "stage-segment-bytes",
#endif
};
const char* const kCallClassNames[kCallClassCount] = {
@@ -211,7 +236,7 @@ namespace MobileGL::MG_Util::PipeStats {
"render-state-cso-mints", "render-state-cso-binds", "map-persistent-roundtrips",
"framebuffer-emissions", "sampler-view-emissions", "sampler-state-emissions",
"shader-image-emissions", "client-tex-upload-emissions", "tex-remint-pulls",
"residual-pulls", "server-verb-boundaries",
"residual-pulls", "server-verb-boundaries", "wire-records",
#endif
};
const char* const kGateNames[kGateCount] = {
@@ -236,7 +261,7 @@ namespace MobileGL::MG_Util::PipeStats {
const char* const kByteClassShort[kByteClassCount] = {"buf", "tex", "ubog", "ubon", "vtxc",
"idxc", "icmd", "pmap", "resid",
#if MOBILEGL_PIPE_PUSH
"csob-blob",
"csob-blob", "seg",
#endif
};
const char* const kGateShort[kGateCount] = {"ers", "etl", "eub", "mfp", "mpm", "mdt"};
@@ -265,6 +290,11 @@ namespace MobileGL::MG_Util::PipeStats {
}
g_frameCount.store(0, std::memory_order_relaxed);
g_windowBaseFrames = 0;
#if MOBILEGL_PIPE_PUSH
for (Uint32 i = 0; i < kStagedBlobHistogramBuckets; ++i) {
g_totalStagedBlobBuckets[i].store(0, std::memory_order_relaxed);
}
#endif
#if MOBILEGL_PIPE_PUSH
for (Uint32 i = 0; i < kGaugeCount; ++i) {
g_gauges[i].store(0, std::memory_order_relaxed);
@@ -284,13 +314,57 @@ namespace MobileGL::MG_Util::PipeStats {
}
void WriteJsonDump() {
#if MOBILEGL_BUILD_DISAGGREGATED
// ---- THE DUMP PATH IS ROLE-DERIVED, AND THIS BLOCK IS WHY IT IS INSIDE A GUARD ----
//
// Same reason as the log path it mirrors: under `spawn` there are two processes with
// two independent sets of counters, each reaching PipeStats::Shutdown(), and one
// configured path would have the second truncate and overwrite the first. A reader
// would then hold one role's numbers under a name that claims to be the run's, which is
// worse than a missing file because nothing about it looks wrong.
//
// THE BASE NAME RESOLVES TO NO FILE, deliberately. `<base>.client.json` and
// `<base>.server.json` are what exist; opening the bare configured name fails loudly.
// That is the log sink's own design ("with both names moved, an un-updated reader gets
// ENOENT and says so") and it is the right trade here too: a caller that has not been
// updated gets an error it must look at, rather than a file that is silently half a run.
//
// THE RULE IS NOT COPIED. MG_Util/Debug/Log.cpp owns `<stem>.<role><ext>` and exports
// it; a second implementation is a second thing to keep in step, and the one that falls
// behind opens a path nothing writes and reads as "the counters never dumped".
//
// ---- AND G1 IS WHY THE PULL ARM BELOW IS THE ORIGINAL, STATEMENT FOR STATEMENT ----
//
// A monolith build has exactly ONE role, so deriving the path there is a no-op - but
// "a no-op" is not "no bytes", and the gate caught three separate leaks as this was
// written. They are worth recording because none is guessable from the code:
//
// 1. deriving UNCONDITIONALLY put a std::string temporary and a call into the
// monolith body: .text +24 bytes.
// 2. guarding it but keeping ONE shared `String` local in both arms still reds: the
// two arms are different code even when they compute the same value, and
// `Shutdown()` came out one byte different.
// 3. rewriting the two MGLOG_W format strings to name both the base and the derived
// path moved .rodata by 64 bytes, because a literal is a literal in whichever
// branch it sits and .rodata is measured too.
//
// So the rule for this file is stronger than "guard the new code": the OLD code must be
// left alone, character for character, and every addition lives inside the `#if`.
const String path = RoleDerivedJsonDumpPathForTesting();
if (path.empty()) {
return;
}
#else
// The monolith arm, byte for byte as it was. Do not "tidy" this into the arm above.
const String& path = MG_Config::Features.PipeStatsFile;
if (path.empty()) {
return;
}
#endif
std::ofstream out(path, std::ios::out | std::ios::trunc);
if (!out) {
MGLOG_W("PipeStats: could not open MOBILEGL_PIPE_STATS_FILE='%s' for writing", path.c_str());
MGLOG_W("PipeStats: could not open MOBILEGL_PIPE_STATS_FILE='%s' for writing",
path.c_str());
return;
}
out << FormatJson();
@@ -311,10 +385,27 @@ namespace MobileGL::MG_Util::PipeStats {
? kDefaultSummaryFramePeriod
: static_cast<Uint64>(MG_Config::Features.PipeStatsPeriod);
if (g_pipeStatsEnabled) {
#if MOBILEGL_BUILD_DISAGGREGATED
// THE ROLE-DERIVED PATH IS WHAT IS PRINTED, not the base name. An operator reading
// this banner wants to know which file the run will write, and under split the base
// name is not it - printing the base would send them to a path that is deliberately
// never opened (see WriteJsonDump).
//
// THE PULL ARM OF THIS `#if` IS THE ORIGINAL LINE, and the split arm repeats the same
// format literal rather than sharing one, for the reason WriteJsonDump's header spells
// out: a shared literal or a shared temporary is a byte the monolith build gains for a
// branch it can never take. Two copies of one format string in two arms of one `#if` is
// the price G1 charges for adding anything to this file at all.
const String dumpPath = RoleDerivedJsonDumpPathForTesting();
MGLOG_I("MGPipe stats: counters ON (MOBILEGL_PIPE_STATS), summary every %llu frames%s%s",
static_cast<unsigned long long>(g_summaryPeriod),
dumpPath.empty() ? "" : ", JSON dump to ", dumpPath.c_str());
#else
MGLOG_I("MGPipe stats: counters ON (MOBILEGL_PIPE_STATS), summary every %llu frames%s%s",
static_cast<unsigned long long>(g_summaryPeriod),
MG_Config::Features.PipeStatsFile.empty() ? "" : ", JSON dump to ",
MG_Config::Features.PipeStatsFile.c_str());
#endif
}
}
@@ -367,6 +458,15 @@ namespace MobileGL::MG_Util::PipeStats {
void RecordDrawPayloadBytes(Uint64 bytes) { Bump(g_totalPayloadBuckets[PayloadBucketOf(bytes)], 1); }
#if MOBILEGL_PIPE_PUSH
// P6 gate 8's staged-blob distribution. A count, not a sum: the bytes already have a home
// in stage-segment-bytes, and what this exists to answer is the SHAPE (how many blobs there
// were and how big each one was), which a total cannot express.
void RecordStagedBlobBytes(Uint64 bytes) {
Bump(g_totalStagedBlobBuckets[PayloadBucketOf(bytes)], 1);
}
#endif
void OnPresent() {
// Every frame accumulator is EXCHANGED for zero, and the exchanged value is what gets
// plotted. A read followed by a store(0) would lose any Bump that lands in between -
@@ -422,6 +522,11 @@ namespace MobileGL::MG_Util::PipeStats {
Uint64 TotalPayloadBucket(Uint32 bucket) {
return bucket < kPayloadHistogramBuckets ? Read(g_totalPayloadBuckets[bucket]) : 0;
}
#if MOBILEGL_PIPE_PUSH
Uint64 TotalStagedBlobBucket(Uint32 bucket) {
return bucket < kStagedBlobHistogramBuckets ? Read(g_totalStagedBlobBuckets[bucket]) : 0;
}
#endif
Uint64 FrameCount() { return Read(g_frameCount); }
const char* NameOf(ByteClass byteClass) { return kByteClassNames[static_cast<Uint32>(byteClass)]; }
@@ -522,6 +627,24 @@ namespace MobileGL::MG_Util::PipeStats {
// positive control built on it would fail on the day the debt is paid.
line += " vbs=" +
std::to_string(calls[static_cast<Uint32>(CallClass::ServerVerbBoundaries)]);
// P6 GATE 8's SECOND NUMBER (CONTRACT-P6.md §9 item 8): records/frame AFTER chunking, i.e.
// the count of records the wire encoder actually committed this window rather than the
// number of times an emitter was asked for one. The gap between the two is the whole
// point of the counter: once the stage chunk budget landed, one application call can
// produce several records, so `wrec` is what a frame really costs SEG_CMD and the
// emitter-side counts can no longer answer it. It follows the line's ordinary
// per-frame/window rule - the run total when the window held no Present - like every
// field that is not one of the gauges, and the label says which it is.
//
// `wrec/f` AND NOT `wrec` ALONE, so the deliverable reads off the line directly. Both are
// printed because the pair is self-checking: a per-frame figure whose window total is not
// its numerator times the frame count is a formatting bug, and a per-frame figure over a
// window with no Present in it is the 47x overstatement PipeStatsTest already pins.
line += " wrec=" + std::to_string(calls[static_cast<Uint32>(CallClass::WireRecords)]);
line += " wrec/f=" + (perFrame
? FormatFixed2(calls[static_cast<Uint32>(CallClass::WireRecords)],
windowFrames)
: std::to_string(calls[static_cast<Uint32>(CallClass::WireRecords)]));
// P5's three wire gauges, and THEY ARE RUN TOTALS on a line whose every other field is
// a window - see the Gauge enum for the argument. `maxrec` is R-10's proof obligation
// (BRIEF 8 item 3): the largest single record this run wrote, in BYTES, beside the cap
@@ -635,6 +758,23 @@ namespace MobileGL::MG_Util::PipeStats {
}
json += std::to_string(Read(g_totalPayloadBuckets[i]));
}
#if MOBILEGL_PIPE_PUSH
// P6 gate 8's two per-frame numbers have their JSON homes where every other ByteClass and
// CallClass already does - the `bytes` and `calls` blocks above, under their long names
// (stage-segment-bytes, wire-records) - so there is nothing to add for them here. The
// staged-blob DISTRIBUTION does need one: it is the deliverable MEASUREMENTS.md:342 says
// has never been measured, and like the draw-payload histogram above it is a run-total
// distribution, which is exactly what Tracy cannot plot and this dump exists to carry.
// Bucket 0 is "0 bytes" and bucket n>0 is [2^(n-1), 2^n): the same edges PayloadBucketOf
// gives both histograms, so the two are read the same way.
json += "],\n \"staged-blob-bytes-histogram\": [";
for (Uint32 i = 0; i < kStagedBlobHistogramBuckets; ++i) {
if (i != 0) {
json += ", ";
}
json += std::to_string(Read(g_totalStagedBlobBuckets[i]));
}
#endif
json += "]\n}\n";
return json;
}
@@ -643,4 +783,18 @@ namespace MobileGL::MG_Util::PipeStats {
void ResetForTesting() { ResetCounters(); }
#if MOBILEGL_BUILD_DISAGGREGATED
String RoleDerivedJsonDumpPathForTesting() {
// The SAME expression WriteJsonDump and the Init banner use, reached through the same
// helper - so a change that stopped deriving at either site has to change this too, and the
// test reds. That is the whole point: see the header for why asserting on RoleLogPath
// directly was not a control.
if (MG_Config::Features.PipeStatsFile.empty()) {
return String();
}
return MG_Util::Debug::RoleLogPath(MG_Config::Features.PipeStatsFile.c_str(),
MG_Util::Debug::CurrentThreadRole());
}
#endif
} // namespace MobileGL::MG_Util::PipeStats
MobileGL/MG_Util/Metrics/PipeStats.h
+94
View File
@@ -87,6 +87,32 @@ namespace MobileGL::MG_Util::PipeStats {
// transport would actually have to move for the CSO families, as opposed to what the
// records themselves cost.
CsoBlobBytes,
// P6 GATE 8's FIRST NUMBER (CONTRACT-P6.md §9 item 8), and the reason it is a ByteClass
// rather than one more Gauge: the deliverable is BYTES PER FRAME, and a byte class IS
// the windowed sum this module already divides by the window's frame count. A gauge is
// a run total deliberately (see the Gauge enum) and windowing one is not a thing this
// module does.
//
// WHAT IT MEASURES, AND WHY IT IS NOT ANY OF THE stage-* CLASSES ABOVE. Those count what
// a BACKEND moves into its own driver, on the apply thread, from bytes the wire already
// delivered. This counts what the WIRE put into SEG_STAGE - the client-side staging
// arena a record's blobs are copied into - and it is read as "staged content per frame".
//
// COUNTED AT THE ALLOCATOR, WHICH IS THE ONE CHOKE POINT. Every writer that puts bytes
// into SEG_STAGE reaches them through PipeWireEncoder::StageBytes and that function's
// only allocation call is StageAllocate (PipeWireCodec.h:376), so a single site here
// covers the buffer content walks, the texture slabs, the CSO archives and the
// storage-block names alike. Summing at the CALLERS instead would be a hand-kept list of
// the paths that happen to exist today, and the next producer added would be missing
// from it with nothing to notice - which is the failure mode the site inventory at the
// top of PipeStats.cpp exists to forbid.
//
// IT IS THE PAYLOAD, NOT THE ARENA OCCUPANCY. Align8 slack and the allocator's wrap skip
// (a run that would straddle the segment's end skips the remainder) are real bytes of
// the segment and are NOT counted: neither is content the producer wrote, and neither
// is what MOBILEGL_IPC_STAGE_MB has to hold for one record. The per-blob distribution
// this average hides is the staged-blob histogram below.
StageSegmentBytes,
#endif
Count
};
@@ -195,6 +221,34 @@ namespace MobileGL::MG_Util::PipeStats {
// would start failing on the day the debt is paid. `vbs` is non-zero whenever the
// server applied a verb at all, before and after retirement alike.
ServerVerbBoundaries,
// P6 GATE 8's SECOND NUMBER (CONTRACT-P6.md §9 item 8): "records/frame post-chunking".
//
// ONE PER RECORD THE WIRE ENCODER ACTUALLY WROTE, which is what makes it the
// post-chunking count rather than a restatement of the emitter's call count. Before the
// stage chunk budget landed, one application call produced one record and the question
// could be answered from the emitter's side; now a call whose content is wider than
// MGPipeStageChunkBytes() produces SEVERAL - the buffer content walks cut themselves at
// the budget and one texture level is emitted as whole-width slabs - and only the
// encoder knows how many. So this is counted where the record is committed
// (PipeWireCodec.cpp's EncodeRecord, on the successful path), not where a caller asked
// for one.
//
// A kRecPad RING FILLER IS NOT A RECORD AND IS NOT COUNTED. Those are the bytes Reserve
// lays down when a record would have straddled the ring's boundary; they carry no
// opcode, both sides skip them, and they are already visible in the gauges as ringpads.
// An emission the ring REFUSED is not counted either: EncodeRecord returns kInvalidSeq
// and the caller publishes and retries, so the record is counted once, when it goes.
//
// Read it against the Client*Emission counters above: a sampler/framebuffer/texture set
// that is resolved and then suppressed does not reach this number, so records-per-frame
// is wire traffic while those are emission calls, and the difference between them is
// exactly what the suppressors absorbed.
//
// NOT SetBytes(), and that is the whole reason it is a CallClass rather than a Gauge: the
// deliverable is records PER FRAME, so it needs the windowed division and the label rule
// that goes with it (FormatWindowLine prints the run total instead when the window holds
// no Present).
WireRecords,
#endif
Count
};
@@ -308,6 +362,30 @@ namespace MobileGL::MG_Util::PipeStats {
// emit records only has to add the one call.
inline constexpr Uint32 kPayloadHistogramBuckets = 24;
#if MOBILEGL_PIPE_PUSH
// Per-STAGED-BLOB size histogram, and it is a SECOND histogram rather than a wider
// kPayloadHistogramBuckets because the two answer different questions about different
// populations: the one above is the command payload of a draw (plan section 4.5.7, sizing
// SEG_CMD), this one is how big the blobs a workload stages into SEG_STAGE actually are.
//
// IT EXISTS FOR CONTRACT-P6.md §9 item 8, and MEASUREMENTS.md:342 says in as many words why:
// the chunking work landed (1e7c372e buffer walks, 9469d48e texture slabs) and every
// `maxrec` number the file carries predates it, so "the per-blob byte distribution after
// chunking" had no measurement at all. A per-frame AVERAGE cannot answer it either: an
// average of 8 MiB is the same number whether one blob of 8 MiB was staged or two of 4 MiB
// that the budget should have cut to one. The bucket edges are PayloadBucketOf's, shared so
// the two distributions are read the same way.
//
// PUSH-ONLY like every counter added since P2: its only sampler is the wire encoder, which a
// pull build does not compile, so the array, the reset, the JSON row and the accessor would
// all exist there for a population that could never be sampled (gate G1).
inline constexpr Uint32 kStagedBlobHistogramBuckets = kPayloadHistogramBuckets;
Uint64 TotalStagedBlobBucket(Uint32 bucket);
// Sample one staged blob. Called by the wire encoder where a blob is staged, behind the
// usual Enabled() predicate.
void RecordStagedBlobBytes(Uint64 bytes);
#endif
// Frames between two summary lines when MOBILEGL_PIPE_STATS=1.
inline constexpr Uint64 kDefaultSummaryFramePeriod = 120;
// The period Init() latched from MOBILEGL_PIPE_STATS_PERIOD (kDefaultSummaryFramePeriod
@@ -369,4 +447,20 @@ namespace MobileGL::MG_Util::PipeStats {
void SetEnabledForTesting(Bool enabled);
void ResetForTesting();
#if MOBILEGL_BUILD_DISAGGREGATED
// The role-derived path the JSON dump will actually write, or empty when
// MOBILEGL_PIPE_STATS_FILE is unset. Empty when unset; never the bare configured name.
//
// IT EXISTS BECAUSE THE OBVIOUS TEST IS NOT A CONTROL. The first version of this case asserted
// things about MG_Util::Debug::RoleLogPath directly - that the two roles get different paths,
// that neither equals the base name. Every one of those assertions passes with the fix REVERTED,
// because they test the naming helper, which was never broken; what was broken was that
// WriteJsonDump did not CALL it. A test that stays green while the defect is present is worse
// than no test, so this accessor exists to make the call site itself observable.
//
// Guarded on the DISAGGREGATED option rather than PIPE_PUSH, because the collision it describes
// only exists with two roles - a monolith build has one and needs no derivation (gate G1).
String RoleDerivedJsonDumpPathForTesting();
#endif
} // namespace MobileGL::MG_Util::PipeStats
tools/device_bench/p6/README.md
+143
View File
@@ -0,0 +1,143 @@
# `device_bench/p6` — the device A/B session runner
Two scripts that run a **paired performance comparison on a real device** and turn its evidence into
markdown tables. They exist because the quantity a disaggregation A/B reads on (tenths of a
millisecond of client CPU per frame) is smaller than the drift a hand-driven session accumulates
between the CPU samples, the pin evidence and the library's own counters — and those three come from
three different mechanisms. Collected by hand they are minutes apart; collected by one process they
are one window.
| file | role |
|---|---|
| `ab_session.py` | collects: reboot, pin, launch each arm in order, sample per-thread CPU, pull role logs, verify the arm |
| `render_ab.py` | renders: `session-summary.json` → the markdown tables a report needs |
The split is deliberate. The renderer reads only what the runner recorded, so it cannot influence
what was collected.
## Usage
```bash
# One arm is TRANSPORT[:BACKEND[:CASE[:REPEATS]]]; repeat a spec to interleave it.
python tools/device_bench/p6/ab_session.py \
--tree /c/Users/me/mobilegl-snapshot \
--out /c/Users/me/evidence \
--apk /c/Users/me/evidence/trace-debug-signed.apk \
--package top.mobilegl.plugin.trace \
--reboot --fan-level 2 --repeats 3 --session my-session \
--arm monolith:DirectGLES:minecraft-1.21.4-rd12-odinlite-in-world:3 \
--arm inproc:DirectGLES:minecraft-1.21.4-rd12-odinlite-in-world:3 \
--arm spawn:DirectGLES:minecraft-1.21.4-rd12-odinlite-in-world:3
python tools/device_bench/p6/render_ab.py /c/Users/me/evidence/my-session/session-summary.json
```
`--tree` is the tree the APK and the runner come from. Point it at a **snapshot**, not the shared
tree, when anything else is editing the repository: a build that picks up a half-written source file
measures nothing, and the failure is invisible in the result. `--apk` must be signed with a key the
device already trusts for that package — the Gradle release build has no signing config locally
(`SIGNING_*` are CI secrets), so it has to be signed by hand first:
```bash
apksigner sign --ks ~/.android/debug.keystore --ks-pass pass:android \
--ks-key-alias androiddebugkey --key-pass pass:android --out signed.apk unsigned.apk
```
`--package` must match the APK's application id. A development build usually needs a suffix
(`-Pmobilegl.applicationIdSuffix=.mine`) so it can sit **beside** an existing install rather than
replacing it: two APKs signed by different keys cannot share an id, and `adb install -r` fails with
`INSTALL_FAILED_UPDATE_INCOMPATIBLE`. The runner then needs `MOBILEGL_TRACE_PACKAGE` set to the same
id (see `run_android_retrace_local.py`'s note beside `BACKENDS`), which `ab_session.py` does itself.
## What the protocol guarantees
The whole point of the script is that these are not optional:
- **Reboot-clean.** `--reboot` reboots, waits for `sys.boot_completed`, and compares the boot id
before and after. An unchanged id means no reboot happened, which is reported as a failure rather
than recorded as a clean window.
- **Pinned frequencies, with evidence.** Every arm runs `pin_device.sh <serial> pin` before and
`... check` after; a non-`PINNED` exit voids the arm (`status: UNPROVEN`), it does not degrade it.
Un-pinned per-thread CPU is not comparable across arms.
- **One thermal window.** All arms in one session, interleaved by the order the `--arm` flags are
given, with a cool-down between them so a later arm is not measured hotter than an earlier one.
- **Arm proof.** Each arm is checked against the library's OWN private log: the transport marker, the
split knobs in the `Config: IPC` line, and for `spawn` the `spawn ARMED - the server role runs in
pid N` line — which only the client writes after launch, connect and handshake all succeeded. A
spawn lane that silently fell back to monolith passes every other check and fails this one.
## Evidence layout
```
<out>/<session>/
session-summary.json # session metadata: boot ids, fan, APK hash, per-arm summaries
<NN>-<case>-<backend>-<transport>-r<N>/
arm-summary.json # this arm: status, problems, cpu, stats, benchmark runs
pin-before.txt pin-after.txt
mobilegl.client.log mobilegl.server.log # per role
benchmark-run1..N.json # per-frame wall + CPU series per repeat
benchmark.json result.json logcat.txt runner.stdout.txt runner.stderr.txt
```
### Two asymmetries of the `spawn` shape that the renderer handles
Both are structural — the client and the server really are different processes — and both produce a
zero that looks like a measurement if read carelessly:
1. **`srv`/`srvpark` live in the server log.** The apply thread publishes them into its own process's
PipeStats. Under `inproc` both roles are threads of one process, so the client's summary line
carries all four numbers; under `spawn` the client prints `srv=0 srvpark=0`, which means "another
process", not "never waited". `render_ab.py` reads the server pair from `mobilegl.server.log`.
2. **The frame count lives in the server log too.** `frames=` is bumped by `PipeStats::OnPresent`,
which the backend calls on Present — and under `spawn` present is applied in the server process,
so the client's `frames=0 window=0`. That zero is the same shape as `srv=0`. The per-frame rates
therefore divide by whichever log counted the frames, and the rendered table names which one that
was.
## Building the APK
```bash
gradle --no-daemon -p <tree>/android-plugin :app:assembleTraceRelease \
-Pmobilegl.buildDisaggregated=ON -Pmobilegl.buildDisaggregatedInproc=ON \
-Pmobilegl.pipePush=ON -Pmobilegl.debuggableRelease=true \
-Pmobilegl.applicationIdSuffix=.mine -Pmobilegl.apkSuffix=mine
```
`-Pmobilegl.debuggableRelease=true` is not optional: without it the release APK is not `run-as`-able,
`trace-replay-ci.sh` cannot pull the private logs, and every arm produces no library log — which is
indistinguishable from a run that produced none.
## Pitfalls this tooling works around
- **`--transport` is ignored in `--benchmark` mode.** `run_android_retrace_local.py` applies
`--transport` only on its `run_case` path; `run_benchmark_case` passes `args.env` alone. So
`--benchmark --transport spawn` runs monolith under a spawn label. This script passes the transport
as an explicit `--env MOBILEGL_TRANSPORT=…` and verifies it from the library's log.
- **`MOBILEGL_RETRACE_USE_PBUFFER` must be in the CI script's environment**, not passed as `--env` —
`trace-replay-ci.sh` reads it itself to decide the surface shape. Without it the `spawn` arm dies
with `Fatal{UnmigratedSurface, "AndroidNativeWindow@P12"}`, because an `ANativeWindow*` means
nothing in the server's process (Rule H).
- **`MOBILEGL_TRACE_SKIP_INSTALL=1`** keeps the script's own `adb install` out of the window. The
session installs once itself and waits for `dex2oat` to exit first: an `am_kill … due to
installPackageLI` landing inside an arm measures the installer.
- **A stale `benchmark.json` is worse than none.** The runner's result directory is keyed by case and
backend, not by arm, so a failed arm can leave the previous arm's file where `read_benchmark` will
pick it up. The directory is deleted before each arm.
## Known limit
Under `spawn`, the client's **windowed** fields (`frames=`, `window=`, `draws/f`, `wrec/f`,
`bytes/f[…]`) are structurally zero: `PipeStats::OnPresent` runs in the server process (the apply
thread applies the present record), so the spawn client never counts frames. Dividing any counter
by the client's `frames=` is undefined. The renderer therefore takes the frame denominator from the
log that actually counted frames (normally the server's), and names the source in the table.
What is **valid** from the client log is the run-total gauges (`cli`, `clipark`, `maxrec`,
`ringwraps`, …): `PublishGauge` is a store, not an add, so the client's terminal `Shutdown()` line
reports true run totals. Symmetrically, the server log's `cli=0` and the client log's `srv=0` mean
"the other process", not "never waited".
The server's own byte/record/wait classes are available since `PipeStats::Init()` runs in
`ServerMain.cpp` (P6 closeout; before that the server log carried no summary line at all and `srv`
had to be reported as unavailable).
tools/device_bench/p6/ab_session.py
+891
View File
@@ -0,0 +1,891 @@
#!/usr/bin/env python3
"""Paired A/B on a disaggregated-campaign device: one reboot-clean thermal window, interleaved arms.
Its first use was `CONTRACT-P6.md` section 9 item 7 (the paired device gate) and item 8-1 (the
doorbell ledger), and it is not specific to those: the thing it computes is "N transports, one
thermal window, identical protocol" for any transport/backend/case triple the runner accepts.
Everything it does is a step of the protocol in docs/Disaggregated/MEASUREMENTS.md sections 4.4 / 9
/ 11 plus notes/p5f/device-report.md.
Why it is a script and not a shell transcript: a run that wants to be quotable needs the CPU
samples, the pin evidence and the library's own wait ledger to come from the SAME window, and the
three of those are collected by three different mechanisms. Collected by hand they drift apart by
minutes, and the quantity being compared (a few tenths of a millisecond per frame between two
transports) is smaller than that drift.
WHAT IT DELIBERATELY DOES NOT DO.
- It does not decide anything about correctness. Benchmark mode takes no snapshot and compares no
golden (--benchmark replays the whole trace for timing), so an SSIM column here would be a
fabrication. Correctness on this device is P6 section 3 of CURRENT_STAGE_PROGRESS.md and the
retrace lanes.
- It does not read `MOBILEGL_TRANSPORT` out of `--transport` on the runner. That flag is applied by
run_android_retrace_local.py's run_case() path only; run_benchmark_case() passes `args.env`
alone, so `--transport spawn` alongside `--benchmark` is silently ignored and the arm runs
monolith while its label says spawn. Measured on this tree (a `--benchmark` run with
`--transport inproc` wrote no `Config: IPC` line at all, i.e. it was monolith). Every arm here
therefore spells its transport as an explicit `--env` entry, and every arm is verified against
the library's own log afterwards. `assert_arm` is the gate on that; an arm that does not prove
itself is not measured, it is retried and then reported as a failure.
"""
from __future__ import annotations
import argparse
import json
import os
import re
import shutil
import signal
import subprocess
import sys
import threading
import time
from datetime import datetime, timezone
from pathlib import Path
SERIAL = "2f7cbe2e"
def find_git_bash():
"""The interpreter that runs pin_device.sh, resolved rather than hardcoded.
Named explicitly because a bare `bash` on a host with several installations picks whichever is
first on PATH, and MSYS path translation differs between them - the failure mode is a
`No such file or directory` for a script that exists, which reads like a missing file rather
than a wrong interpreter.
"""
import shutil
candidates = [
os.environ.get("GIT_BASH"),
r"C:\Program Files\Git\bin\bash.exe",
r"C:\Program Files (x86)\Git\bin\bash.exe",
shutil.which("bash"),
]
for candidate in candidates:
if candidate and Path(candidate).exists():
return candidate
return "bash"
GIT_BASH = find_git_bash()
# The knobs CI's split acceptance lanes hand both arms, kept verbatim so a local run is the same
# run (run_android_retrace_local.py SPLIT_ACCEPTANCE_KNOBS). The arm proof reads the library's own
# `Config: IPC` line and requires all three, so omitting one here does not measure a weaker arm -
# it fails to prove any arm at all.
SPLIT_KNOBS = (
"MOBILEGL_IPC_ROLE_SPLIT_STATE=1",
"MOBILEGL_IPC_STRICT_ERRORS=1",
"MOBILEGL_IPC_RUN_AHEAD=1",
)
# 120 is the P5-era default and it is what every historical number in MEASUREMENTS.md sections 9-11
# was taken at, so the wait ledger here can be read beside them.
STATS_PERIOD = "120"
TRANSPORT_MARKERS = {
"inproc": "Config: MOBILEGL_TRANSPORT=inproc",
"spawn": "Config: MOBILEGL_TRANSPORT=spawn",
}
SPAWN_ARMED = re.compile(r"spawn ARMED - the server role runs in pid (\d+)")
WAIT_LEDGER = re.compile(
r"wait\[srv=(\d+) srvpark=(\d+) cli=(\d+) clipark=(\d+)\]")
SECTION = re.compile(r"\] ([a-z]+)\[")
STAGE_LINE = re.compile(r"stage=(\d+)MiB")
def run(argv, **kwargs):
kwargs.setdefault("capture_output", True)
kwargs.setdefault("text", True)
kwargs.setdefault("encoding", "utf-8")
kwargs.setdefault("errors", "replace")
return subprocess.run(argv, **kwargs)
class Adb:
"""Every call pins the serial. There is more than one device class on this bench and a bare
`adb` is how a run measures the wrong phone."""
def __init__(self, serial):
self.serial = serial
@staticmethod
def _env():
env = dict(os.environ)
env["MSYS_NO_PATHCONV"] = "1"
env["MSYS2_ARG_CONV_EXCL"] = "*"
return env
def shell(self, command, timeout=30):
result = run(["adb", "-s", self.serial, "shell", command], env=self._env(), timeout=timeout)
return result.stdout.replace("\r", "")
def su(self, command, timeout=30):
return self.shell("su -c '%s'" % command, timeout=timeout)
def reboot(self):
# `adb reboot` returns as soon as the request is queued; the wait is the caller's.
run(["adb", "-s", self.serial, "reboot"], env=self._env(), timeout=60)
def wait_boot(self, timeout=300):
deadline = time.time() + timeout
run(["adb", "-s", self.serial, "wait-for-device"], env=self._env(), timeout=timeout)
while time.time() < deadline:
state = self.shell("getprop sys.boot_completed").strip()
if state == "1":
return True
time.sleep(3)
return False
def boot_id(self):
return self.shell("cat /proc/sys/kernel/random/boot_id").strip()
def clk_tck(self):
"""The DEVICE's tick rate, which is what /proc/<pid>/stat's counters are denominated in.
Read rather than assumed, and not the host's CLK_TCK: a 100-vs-250 mismatch would scale
every CPU millisecond in the report by 2.5x and nothing downstream could tell.
"""
value = self.shell("getconf CLK_TCK").strip()
try:
return int(value)
except ValueError:
return host_ticks_per_second()
def host_ticks_per_second():
"""Only a fallback. The authoritative tick rate is the DEVICE's, read in Adb.__init__ -
/proc/<pid>/stat reports ticks, and a host that assumes its own CLK_TCK while the device uses
another silently scales every CPU number by the ratio."""
try:
return int(subprocess.run(["getconf", "CLK_TCK"], capture_output=True, text=True).stdout.strip())
except Exception:
return 100
TICKS = host_ticks_per_second()
class CpuSampler:
"""Per-thread CPU over the arm, sampled from the host.
`/proc/<pid>/task/<tid>/stat` rather than the process total, because the quantity under
comparison is a PER-THREAD one: the kernel ignores this app's affinity requests, so the client
GL thread and the apply thread land on different clusters and a process total mixes two
different clock domains (MEASUREMENTS.md section 9's caveat, which is why the primary metric is
the client thread's CPU and not wall time).
Under `spawn` the server role is a separate PROCESS, so the same read is taken against that pid
as well - `/proc/<serverpid>/task/*` yields exactly the server's threads, and `libMobileGLServer.so`
is the process name that identifies it.
Read as a delta between two samples, so the residual is bounded by one poll interval and is
reported rather than hidden: `first_utc`/`last_utc` are written into the summary.
"""
def __init__(self, adb, package, interval=0.5):
self.adb = adb
self.package = package
self.interval = interval
self._stop = threading.Event()
self._thread = None
self.samples = []
def _read_once(self):
# THE DEVICE SIDE ONLY LOCATES THE NUMBERS; EVERY FIELD IS INDEXED ON THIS SIDE.
#
# `stat` is `pid (comm) state ...` and comm is its ONLY space-bearing field, so the split
# point is the LAST ')' - which is a two-line string operation and belongs in Python, not in
# a device-side program trying to survive three layers of shell quoting. Two attempts at
# doing it on the device failed differently and both looked like data: `set -- $(cat stat);
# echo $14` is `$1` followed by a literal 4 on Android's sh, so the sampler echoed the pid
# into every counter column and every delta came out 0; and an inline `awk` program cannot be
# written inside `su -c '...'` without its own quotes closing that wrapper, which surfaces as
# `/system/bin/sh: syntax error: unexpected '('` and an empty read.
#
# So the device-side text is one line per thread with no quotes at all:
# <pid> <tid> |<the whole raw stat line>
# and `summarize_cpu` never sees the raw text - only the counters parsed out of it here.
#
# Comm is truncated to 15 characters by the kernel, so `MobileGLTraceReplay` reads back as
# `MobileGLTraceRe`; matching is on the PREFIX.
script = (
"P=$(pidof %s); S=$(pidof libMobileGLServer.so); "
"for pid in $P $S; do "
"[ -n \"$pid\" ] || continue; "
"for t in /proc/$pid/task/*; do "
"echo \"$pid ${t##*/} | $(cat $t/stat 2>/dev/null)\"; "
"done; done"
) % self.package
out = self.adb.su(script, timeout=25)
rows = []
for line in out.splitlines():
head, sep, stat_line = line.partition("|")
if not sep:
continue
ids = head.split()
if len(ids) < 2 or ")" not in stat_line:
continue
open_paren = stat_line.find("(")
close_paren = stat_line.rfind(")")
if open_paren < 0 or close_paren < open_paren:
continue
# After the ')', stat's fields are: state(3) ppid(4) ... utime(14) stime(15) ...
# starttime(22). `tail` is that sequence, so stat's field N sits at 0-based N-3.
tail = stat_line[close_paren + 1:].split()
if len(tail) < 20:
continue
try:
rows.append({
"pid": int(ids[0]), "tid": int(ids[1]),
"comm": stat_line[open_paren + 1:close_paren],
"utime": int(tail[14 - 3]), "stime": int(tail[15 - 3]),
"starttime": int(tail[22 - 3]),
})
except ValueError:
continue
return rows
def _loop(self):
while not self._stop.is_set():
try:
rows = self._read_once()
except Exception:
rows = []
if rows:
self.samples.append((time.time(), rows))
self._stop.wait(self.interval)
def start(self):
self._thread = threading.Thread(target=self._loop, daemon=True)
self._thread.start()
def stop(self):
self._stop.set()
if self._thread:
self._thread.join(timeout=10)
def replay_windows(self, min_seconds=1.0):
"""Split the samples into one window PER REPLAY.
TWO BOUNDARIES, because neither alone is sufficient:
1. A CHANGE IN THE PACKAGE'S MAIN THREAD IDENTITY. Each repeat is a separate app launch -
trace-replay-ci.sh force-stops the package and `am start`s it again - so the main thread
has a new tid. This is the structural boundary and needs no threshold.
2. A GAP WIDER THAN THREE POLL INTERVALS. Pids are recycled, and on a device that is
force-stopping and restarting one app, two consecutive replays really can receive the
same pid; the dead interval between them is then the only evidence that they were two
launches rather than one long one. The gap is also what separates the app sitting idle
from the app replaying.
This matters because the divisor and the CPU counters have to describe the SAME stretch of
work. Summing CPU across three replays and dividing by ONE replay's frame count reports three
times the real per-frame cost; pairing a window with the wrong repeat's frames does the same
thing less visibly.
Returns a list of (start_index, length) in sample order, keeping only windows at least
`min_seconds` long: shorter than that is start-up or teardown, not a replay.
"""
if not self.samples:
return []
def main_pid(rows):
"""The pid of the CLIENT process, or None if it is not in this sample.
Identified as "the process whose thread with tid == pid is not the server binary". tid ==
pid is the definition of a main thread, so that half needs no evidence; the server
exclusion is needed because under `spawn` the server process is a separate main thread in
the same sample set.
NOT matched on the package name: Android's comm for a main thread is the TAIL of the
process name truncated to 15 characters (`top.mobilegl.plugin.p6gate8.trace` reads back
as `n.p6gate8.trace`), so a prefix comparison against `top.mobilegl...` never matches and
would silently produce zero windows.
"""
for row in rows:
if row["tid"] != row["pid"]:
continue
if row["comm"].startswith("libMobileGL"):
continue
return row["pid"]
return None
gap_limit = self.interval * 3
windows = []
run_start = 0
current_pid = main_pid(self.samples[0][1])
for index in range(1, len(self.samples)):
stamp, rows = self.samples[index]
pid = main_pid(rows)
gap = stamp - self.samples[index - 1][0]
pid_changed = pid is not None and current_pid is not None and pid != current_pid
if pid_changed or gap > gap_limit:
windows.append((run_start, index - run_start))
run_start = index
if pid is not None:
current_pid = pid
windows.append((run_start, len(self.samples) - run_start))
kept = []
for start, length in windows:
span = self.samples[start + length - 1][0] - self.samples[start][0]
if span >= min_seconds:
kept.append((start, length))
return kept
def summarize_cpu(samples, clock_ticks):
"""Per-thread CPU milliseconds over the sample window, keyed by (pid, tid, starttime).
THE WINDOW IS ANCHORED ON EACH THREAD'S OWN FIRST AND LAST SIGHTING, not on the first and last
sample. The app's threads are not all alive for the whole window - the GL thread is created when
the replay starts, and under `spawn` the server process appears partway through - so a single
global pair of timestamps would report every late thread's counter as if it had been spent since
the window opened, i.e. as an overcount, and would report a thread that exited early as zero.
Anchoring per thread makes `cpu_ms` the CPU that thread really consumed while it existed; the
window it did so in is `window_seconds`, which is per thread for the same reason.
`ms_per_frame` is filled in by the caller, which is the only place that knows the frame count
and the frame-to-frame mapping.
"""
if len(samples) < 2:
return {"threads": [], "window_seconds": 0.0, "clock_ticks": clock_ticks}
sightings = {}
for index, (stamp, rows) in enumerate(samples):
for row in rows:
# IDENTITY IS (pid, tid, STARTTIME). Two threads can share a tid across a process's
# lifetime - the kernel recycles them - and a short-lived thread spawned near the end of
# a window has tid values that look like an unrelated long-lived one's. Keying on
# (pid, tid) alone merged those and produced a handful of phantom entries with one
# sample each: under inproc the OpenRA replay's real GL thread showed up three times,
# once with the right 880 ms and twice with 0. `starttime` is what tells them apart, and
# it is why the device-side read carries field 22.
key = (row["pid"], row["tid"], row["starttime"])
entry = sightings.setdefault(key, {
"pid": row["pid"], "tid": row["tid"], "comm": row["comm"],
"first_index": index, "last_index": index, "first": row, "last": row, "count": 0,
})
entry["last_index"] = index
entry["last"] = row
entry["count"] += 1
threads = []
for entry in sightings.values():
dticks = ((entry["last"]["utime"] - entry["first"]["utime"]) +
(entry["last"]["stime"] - entry["first"]["stime"]))
span = samples[entry["last_index"]][0] - samples[entry["first_index"]][0]
threads.append({
"pid": entry["pid"], "tid": entry["tid"], "comm": entry["comm"],
"cpu_ms": round(1000.0 * dticks / clock_ticks, 3),
"window_seconds": round(span, 3),
"samples": entry["count"],
"starttime": entry["first"]["starttime"],
# A thread seen in only ONE sample has no delta to measure, and `cpu_ms` for it is 0 by
# construction rather than by evidence. Flagged rather than dropped so the row can be
# excluded from the ROLE table while still being visible in the raw dump - a thread that
# only ever appeared once is not a measurement of anything, and a table that averages it
# in as a zero is worse than one that omits it.
"measurable": entry["count"] > 1,
})
threads.sort(key=lambda t: -t["cpu_ms"])
return {
"threads": threads,
"window_seconds": round(samples[-1][0] - samples[0][0], 3),
"clock_ticks": clock_ticks,
"first_utc": datetime.fromtimestamp(samples[0][0], timezone.utc).isoformat(),
"last_utc": datetime.fromtimestamp(samples[-1][0], timezone.utc).isoformat(),
}
def read_stats_line(log_path):
"""The LAST `MGPipe stats:` line in a role log, parsed.
Last and not first: the line is a WINDOW, and the first window of a run contains load and
shader warm-up. The last is the closest thing to steady state the trace has (for rd12, the
trailing window of a 251-frame benchmark).
"""
if not Path(log_path).is_file():
return None
last = None
with open(log_path, encoding="utf-8", errors="replace") as handle:
for line in handle:
if "MGPipe stats:" in line:
last = line.strip()
if last is None:
return None
parsed = {"raw": last}
ledger = WAIT_LEDGER.search(last)
if ledger:
parsed["wait"] = {
"srv": int(ledger.group(1)), "srvpark": int(ledger.group(2)),
"cli": int(ledger.group(3)), "clipark": int(ledger.group(4)),
}
window = re.search(r"window=(\d+)", last)
if window:
parsed["window_frames"] = int(window.group(1))
frames = re.search(r"\bframes=(\d+)", last)
if frames:
parsed["run_frames"] = int(frames.group(1))
draws = re.search(r"draws/f=([\d.]+)", last)
if draws:
parsed["draws_per_frame"] = float(draws.group(1))
# The byte classes, keyed by their short names, straight out of the `bytes/f[...]` bracket.
bracket = re.search(r"bytes/f\[([^\]]*)\]", last) or re.search(r"bytes\[([^\]]*)\]", last)
if bracket:
for entry in bracket.group(1).split():
if "=" in entry:
name, value = entry.split("=", 1)
try:
parsed.setdefault("bytes_per_frame", {})[name] = float(value)
except ValueError:
pass
maxrec = re.search(r"maxrec=(\d+)", last)
if maxrec:
parsed["max_record_bytes"] = int(maxrec.group(1))
maxcap = re.search(r"maxcap=(\d+)", last)
if maxcap:
parsed["max_record_cap"] = int(maxcap.group(1))
ringwaits = re.search(r"ringwaits=(\d+)", last)
if ringwaits:
parsed["ring_waits"] = int(ringwaits.group(1))
return parsed
class Arm:
def __init__(self, spec, args, out_root, index):
fields = spec.split(":")
self.transport = fields[0]
self.backend = fields[1] if len(fields) > 1 else "DirectGLES"
self.case = fields[2] if len(fields) > 2 else None
self.repeats = int(fields[3]) if len(fields) > 3 else args.repeats
self.tree = Path(args.tree).resolve()
self.package = args.package
self.label = f"{index:02d}-{self.case}-{self.backend}-{self.transport}-r{self.repeats}"
self.dir = out_root / self.label
self.dir.mkdir(parents=True, exist_ok=True)
self.adb = Adb(args.serial)
self.summary = {
"label": self.label, "case": self.case, "backend": self.backend,
"transport": self.transport, "repeats": self.repeats,
}
def env_overrides(self):
env = ["MOBILEGL_PIPE_STATS=1", f"MOBILEGL_PIPE_STATS_PERIOD={STATS_PERIOD}"]
if self.transport != "monolith":
env.insert(0, f"MOBILEGL_TRANSPORT={self.transport}")
env.extend(SPLIT_KNOBS)
return env
@staticmethod
def surface_env():
"""The surface shape, exported rather than passed as an override - and that distinction is
load-bearing.
`MOBILEGL_RETRACE_USE_PBUFFER` is read by trace-replay-ci.sh ITSELF, to decide whether to
add `--ez use_pbuffer true` to the activity intent. A `--env MOBILEGL_RETRACE_USE_PBUFFER=1`
override only reaches the applier of env knobs deep inside the replay process, which is a
different mechanism and does not set that shell variable - so the retrace still asks for a
window surface.
That is fatal on the spawn arm and only there: an ANativeWindow* is a pointer into the
CLIENT's process and the wire refuses it by name (Rule H). Measured on this tree - the spawn
arm died with `Fatal{UnmigratedSurface, "AndroidNativeWindow@P12"}` published as a
SessionFault, and the same run passes as soon as the variable is in the script's environment.
"""
return {"MOBILEGL_RETRACE_USE_PBUFFER": "1"}
def result_dirs(self):
"""The runner's result directory for this case/backend (it is fixed, not per-arm)."""
safe = "".join(c if c.isalnum() or c in "._-" else "_" for c in self.case)
return self.tree / ".trace-work" / "android-retrace-result" / f"{safe}-{self.backend}"
def build_command(self):
return [
sys.executable, "tools/trace_replay/run_android_retrace_local.py",
"--case", self.case, "--backend", self.backend, "--keep-results",
"--benchmark", "--benchmark-repeats", str(self.repeats),
"--benchmark-tail-frames", "200", "--benchmark-no-finish",
"--benchmark-timeout-seconds", "1800",
"--env", ";".join(self.env_overrides()),
]
def child_env(self):
env = dict(os.environ)
env["ANDROID_SERIAL"] = self.adb.serial
# Snapshot-local override so this build can sit beside an unrelated trace install under
# the canonical id (see run_android_retrace_local.py's note beside BACKENDS).
env["MOBILEGL_TRACE_PACKAGE"] = self.package
# The session installs the APK once, before the thermal window opens; the script's own
# `adb install -r` on the first repeat would otherwise run inside it. trace-replay-ci.sh
# puts its install behind this variable and leaves `copy_fixture_to_app` OUTSIDE the same
# branch, so skipping the install still gets the trace and golden onto the device - which
# matters here because the first repeat of every arm is a `reuse_fixture == 0` run.
env["MOBILEGL_TRACE_SKIP_INSTALL"] = "1"
env.update(self.surface_env())
env["PYTHON"] = sys.executable
env["MSYS2_ARG_CONV_EXCL"] = "/data/*"
env.pop("MSYS_NO_PATHCONV", None)
return env
def pin(self, action):
# Git Bash needs its own path form: `bash C:/Users/...` is not a path it resolves (measured
# "No such file or directory" for a script that exists). The /c/ form is what its own
# MSYS path layer understands, and the interpreter is named explicitly because a bare
# `bash` on this host can resolve to something that is not Git Bash at all.
script = self.tree.as_posix().replace("C:/", "/c/") + "/tools/device_bench/pin_device.sh"
result = run([GIT_BASH, script, self.adb.serial, action], cwd=str(self.tree))
return result.returncode, result.stdout + result.stderr
def thread_role(self, thread):
"""Which of the two roles this thread carries, from its name and its process.
The kernel truncates comm to 15 characters, so the names to match are PREFIXES:
`MobileGLTraceReplay` is `MobileGLTraceRe`, and `mgl-srv-apply` survives intact.
Under `spawn` the whole server process is the server role, so every thread of that process
counts as one - the interesting one is whichever thread is busy, and naming it by process is
both simpler and truer than guessing from comm (the apply thread is named `mgl-srv-apply`
there too, but a future server-side thread would not be).
"""
if self.transport == "spawn" and thread["pid"] == self.summary.get("server_pid"):
return "server-process"
name = thread["comm"]
if name.startswith("MobileGLTraceRe"):
return "client-gl"
if name.startswith("mgl-srv"):
return "apply"
return "other"
def run(self):
self.summary["boot_id"] = self.adb.boot_id()
self.summary["started_utc"] = datetime.now(timezone.utc).isoformat()
# PURGE THE PREVIOUS ARM'S ARTEFACTS BEFORE THIS ONE STARTS, and not after it ends.
# The runner's result directory is keyed by case and backend, not by arm, so arm N+1
# overwrites arm N's benchmark.json in place - and if arm N+1 fails early it leaves arm N's
# file sitting there under arm N+1's name. `read_benchmark` cannot tell: it reads whatever is
# at that path and files it as this run's result. Deleting first makes "no file" the only
# thing a failed run can leave behind, which `assert_arm` already refuses.
result_dir = self.result_dirs()
if result_dir.exists():
shutil.rmtree(result_dir)
gen, text = self.pin("pin")
(self.dir / "pin-before.txt").write_text(text, encoding="utf-8")
self.summary["pin_before_rc"] = gen
if gen != 0:
self.summary["status"] = "PIN_FAILED_BEFORE"
return
# FORCE-STOP AND WAIT FOR IT TO ACTUALLY BE GONE BEFORE THE SAMPLER OPENS.
#
# A leftover instance from an earlier arm or an earlier session keeps answering `pidof`, so
# the sampler counts it as part of this arm's window - measured: a stray idle instance from a
# previous smoke run put 14 samples in front of the real repeat and made the window count
# disagree with the repeat count. trace-replay-ci.sh force-stops the package too, but only
# after it has pushed the fixture, which is well inside the sampler's lifetime; doing it here
# as well means the sampler's first sample cannot see anything but this arm.
self.adb.shell(f"am force-stop {self.package}")
for _ in range(20):
if not self.adb.shell(f"pidof {self.package}").strip():
break
time.sleep(0.5)
sampler = CpuSampler(self.adb, self.package)
sampler.start()
try:
result = run(self.build_command(), cwd=self.tree, env=self.child_env(), timeout=2000)
stdout = result.stdout
stderr = result.stderr
rc = result.returncode
except subprocess.TimeoutExpired as error:
stdout = (error.stdout or b"").decode("utf-8", "replace")
stderr = (error.stderr or b"").decode("utf-8", "replace")
rc = 124
finally:
sampler.stop()
(self.dir / "runner.stdout.txt").write_text(stdout, encoding="utf-8")
(self.dir / "runner.stderr.txt").write_text(stderr, encoding="utf-8")
self.summary["runner_rc"] = rc
# ONE WINDOW PER REPLAY, matched to that repeat's own frame count. See
# CpuSampler.replay_windows: the boundary is the package's main-thread identity, and the
# divisor has to be the frames replayed inside the SAME window or the ratio is off by the
# repeat count in whichever direction the mistake was made.
windows = sampler.replay_windows()
clock = self.adb.clk_tck()
per_repeat = []
for index, (start, length) in enumerate(windows):
window = sampler.samples[start:start + length]
per_repeat.append({
"repeat": index + 1,
"start_utc": datetime.fromtimestamp(window[0][0], timezone.utc).isoformat(),
"end_utc": datetime.fromtimestamp(window[-1][0], timezone.utc).isoformat(),
"samples": length,
"cpu": summarize_cpu(window, clock),
})
self.summary["sampler"] = {
"total_samples": len(sampler.samples),
"windows": len(windows),
"per_repeat": per_repeat,
}
result_dir = self.result_dirs()
for role in ("client", "server"):
source = result_dir / f"mobilegl.{role}.log"
if source.is_file():
shutil.copyfile(source, self.dir / f"mobilegl.{role}.log")
for name in ("benchmark.json", "transport-proof.json", "result.json", "logcat.txt"):
source = result_dir / name
if source.is_file():
shutil.copyfile(source, self.dir / name)
self.summary["stats"] = {
"client": read_stats_line(self.dir / "mobilegl.client.log"),
"server": read_stats_line(self.dir / "mobilegl.server.log"),
}
reports = []
for path in sorted(result_dir.glob("benchmark-run*.json")):
try:
reports.append(json.loads(path.read_text(encoding="utf-8")))
except ValueError:
pass
if not reports and (result_dir / "benchmark.json").is_file():
reports.append(json.loads((result_dir / "benchmark.json").read_text(encoding="utf-8")))
self.summary["benchmark_runs"] = reports
# THE ms/FRAME COLUMN IS COMPUTED FOR EVERY REPEAT, not just the best one, and the best-of-N
# row is chosen exactly as run_android_retrace_local.py chooses it - lowest mean frame time -
# so this row and the runner's own summary line describe one run rather than a median of a
# median.
#
# `repeat_count_matches_windows` is checked rather than assumed: every per-frame column pairs
# window N with repeat N, so if one record has a replay the other does not, the pairs are
# wrong in a way no individual number would reveal.
self.summary["repeat_count_matches_windows"] = len(reports) == len(per_repeat)
for index, repeat in enumerate(per_repeat):
repeat["repeat"] = index + 1
report = reports[index] if index < len(reports) else {}
repeat["benchmark"] = {
"totalFrames": report.get("totalFrames"), "tailFrames": report.get("tailFrames"),
"meanFrameMs": report.get("meanFrameMs"), "medianFrameMs": report.get("medianFrameMs"),
"p95FrameMs": report.get("p95FrameMs"), "fps": report.get("fps"),
}
frames = report.get("totalFrames") or 0
for thread in repeat["cpu"]["threads"]:
thread["role"] = self.thread_role(thread)
if frames:
thread["cpu_ms_per_frame"] = round(thread["cpu_ms"] / frames, 4)
if reports:
best_index, best = min(
enumerate(reports),
key=lambda pair: pair[1].get("meanFrameMs", -1) if pair[1].get("meanFrameMs", -1) > 0 else float("inf"),
)
self.summary["best_repeat"] = {
"index": best_index + 1,
"totalFrames": best.get("totalFrames"), "tailFrames": best.get("tailFrames"),
"meanFrameMs": best.get("meanFrameMs"), "medianFrameMs": best.get("medianFrameMs"),
"p95FrameMs": best.get("p95FrameMs"), "fps": best.get("fps"),
"meanFrameCpuMs": best.get("meanFrameCpuMs"),
"medianFrameCpuMs": best.get("medianFrameCpuMs"),
"p95FrameCpuMs": best.get("p95FrameCpuMs"),
}
self.summary["best_repeat_frames"] = best.get("totalFrames") or 0
gen2, text2 = self.pin("check")
(self.dir / "pin-after.txt").write_text(text2, encoding="utf-8")
self.summary["pin_after_rc"] = gen2
self.assert_arm()
self.summary["finished_utc"] = datetime.now(timezone.utc).isoformat()
(self.dir / "arm-summary.json").write_text(
json.dumps(self.summary, indent=2), encoding="utf-8")
def assert_arm(self):
"""Does the library's own log prove the arm it is labelled as?
Two questions, and the second is the one that matters for `spawn`:
1. did the transport resolve to what this arm claims (the ConfigLoader marker), and
2. for spawn, did the server role actually leave this process (the `spawn ARMED` pid line,
which only ClientSession::StartSpawned writes and only after launch+connect+handshake
all succeeded).
A run that resolved spawn and then never reached another process produces the first line and
not the second; a run that fell back to monolith produces neither. Either way the arm is
`status: UNPROVEN` and its numbers are not evidence.
"""
problems = []
client = self.dir / "mobilegl.client.log"
texts = {}
for role in ("client", "server"):
path = self.dir / f"mobilegl.{role}.log"
texts[role] = path.read_text(encoding="utf-8", errors="replace") if path.is_file() else ""
combined = texts["client"] + texts["server"]
expected = TRANSPORT_MARKERS.get(self.transport)
if expected is not None:
if expected not in texts["client"]:
problems.append(f"client log does not carry the transport marker for {self.transport}")
configs = re.findall(r"Config: IPC[^\n]*", texts["client"])
if not configs:
problems.append("no `Config: IPC` line on the client: the split knobs never resolved")
else:
for key in ("strict=1", "role-split-state=1", "run-ahead=1"):
if not any(key in line for line in configs):
problems.append(f"`Config: IPC` line missing {key}")
else:
# The control arm has to be a control: no IPC line and no transport marker.
if "Config: IPC" in combined:
problems.append("monolith arm wrote a `Config: IPC` line: the knobs were armed")
if self.transport == "spawn":
armed = SPAWN_ARMED.search(texts["client"])
if armed is None:
problems.append("no `spawn ARMED - the server role runs in pid N` line: "
"the server never left this process")
else:
self.summary["server_pid"] = int(armed.group(1))
if not texts["server"]:
problems.append("spawn arm has no server-role log")
elif self.transport == "inproc":
if not texts["server"]:
problems.append("inproc arm has no server-role log (the apply thread's own file)")
for path in self.dir.glob("mobilegl.*.log"):
for line in path.read_text(encoding="utf-8", errors="replace").splitlines():
if "Fatal{" in line:
problems.append(f"Fatal{{ in {path.name}: {line.strip()[:200]}")
break
if self.summary.get("pin_before_rc") != 0:
problems.append("pin did not take before the run")
if self.summary.get("pin_after_rc") != 0:
problems.append("pin check AFTER the run did not report PINNED: this arm is void")
if self.summary.get("runner_rc") != 0:
problems.append(f"runner exited {self.summary.get('runner_rc')}")
if not self.summary.get("benchmark_runs"):
problems.append("no benchmark.json was pulled")
self.summary["problems"] = problems
self.summary["status"] = "OK" if not problems else "UNPROVEN"
def main():
parser = argparse.ArgumentParser()
parser.add_argument("--tree", required=True, help="Snapshot tree the APK and runner come from")
parser.add_argument("--out", required=True, help="Evidence root for this session")
parser.add_argument("--serial", default=SERIAL)
parser.add_argument("--package", default="top.mobilegl.plugin.p6gate8.trace",
help="Application id of the installed trace APK. Defaults to the id this "
"campaign's development builds use; pass the canonical "
"top.mobilegl.plugin.trace for a stock install.")
parser.add_argument("--apk", required=True, help="Signed trace APK to install before the window")
parser.add_argument("--arm", action="append", required=True,
metavar="TRANSPORT[:BACKEND[:CASE[:REPEATS]]]",
help="One arm, in the order given. Repeating a spec interleaves it.")
parser.add_argument("--repeats", type=int, default=3)
parser.add_argument("--reboot", action="store_true",
help="Reboot and wait for boot_completed before the window")
parser.add_argument("--fan-level", default="2")
parser.add_argument("--session", default=None)
args = parser.parse_args()
tree = Path(args.tree).resolve()
label = args.session or datetime.now(timezone.utc).strftime("%Y%m%dT%H%M%SZ")
out_root = Path(args.out).resolve() / label
out_root.mkdir(parents=True, exist_ok=True)
adb = Adb(args.serial)
session = {"label": label, "serial": args.serial, "tree": str(tree),
"package": args.package, "apk": str(Path(args.apk).resolve()),
"apk_sha256": subprocess.run(["sha256sum", args.apk], capture_output=True, text=True)
.stdout.split()[0],
"arms": [a for a in args.arm], "repeats": args.repeats,
"stats_period": STATS_PERIOD,
# The DEVICE's tick rate, read here so the session records the divisor every arm's
# CPU number was computed with. `TICKS` (the host's) is only a fallback for a device
# that cannot answer, and printing it here would have looked like the answer.
"device_clock_ticks": adb.clk_tck()}
# The fan is a CONSTANT of the protocol, not a treatment: both arms run under the same airflow,
# and on this device it is the difference between a 60 s cool-down between arms and a 20-minute
# one (notes/p4a/INTEGRATOR-DECISIONS.md). `real_speed` is read back because target_level alone
# is a request, not a fact.
fan = "/sys/class/xm_power/hw_monitor/pwm_fan"
adb.su(f"echo {args.fan_level} > {fan}/target_level")
time.sleep(3)
session["fan"] = {
"target_level": adb.su(f"cat {fan}/target_level").strip(),
"real_speed": adb.su(f"cat {fan}/real_speed").strip(),
"pwm_duty": adb.su(f"cat {fan}/pwm_duty").strip(),
}
if args.reboot:
session["reboot_requested_utc"] = datetime.now(timezone.utc).isoformat()
boot_before = adb.boot_id()
adb.reboot()
if not adb.wait_boot():
print("device did not reach boot_completed", file=sys.stderr)
return 2
# boot_id must have CHANGED, or "reboot-clean" is a claim about a reboot that did not happen.
time.sleep(20)
boot_after = adb.boot_id()
session["boot_id_before"] = boot_before
session["boot_id"] = boot_after
session["rebooted_clean"] = boot_before != boot_after
if not session["rebooted_clean"]:
print(f"boot_id unchanged ({boot_before}): not a clean reboot", file=sys.stderr)
return 2
# Re-assert the fan: an xm_power level does not always survive a reboot.
adb.su(f"echo {args.fan_level} > {fan}/target_level")
time.sleep(3)
else:
session["boot_id"] = adb.boot_id()
session["rebooted_clean"] = False
install = run(["adb", "-s", args.serial, "install", "-r", str(Path(args.apk).resolve())])
session["install"] = (install.stdout + install.stderr).strip().splitlines()[-1:]
# dex2oat outlives the install by a minute or two, and an `am_kill ... due to installPackageLI`
# landing inside the first arm is a measurement of the installer, not of the transport
# (MEASUREMENTS.md section 10). Wait for it by name.
for _ in range(60):
if not adb.shell("ps -A -o NAME | grep -c dex2oat").strip().isdigit():
break
if adb.shell("ps -A -o NAME | grep -c dex2oat").strip() == "0":
break
time.sleep(5)
time.sleep(10)
session["arms"] = []
for index, spec in enumerate(args.arm, start=1):
started = time.time()
arm = Arm(spec, args, out_root, index)
print(f"=== arm {arm.label} ===", flush=True)
arm.run()
session["arms"].append(arm.summary)
print(f" status={arm.summary['status']} problems={arm.summary.get('problems')} "
f"({time.time() - started:.0f}s)", flush=True)
# Between-arm cool-down, gate at 40 C on the CPU-subsystem sensor the pin script reports.
for _ in range(60):
temp = adb.su("cat /sys/class/thermal/thermal_zone13/temp").strip()
try:
if int(temp) <= 36000:
break
except ValueError:
break
time.sleep(5)
(out_root / "session-summary.json").write_text(
json.dumps(session, indent=2), encoding="utf-8")
print(json.dumps({"session": label, "out": str(out_root),
"arms": [{"label": a["label"], "status": a["status"]}
for a in session["arms"]]}, indent=2))
return 0 if all(a["status"] == "OK" for a in session["arms"]) else 1
if __name__ == "__main__":
raise SystemExit(main())
tools/device_bench/p6/render_ab.py
+369
View File
@@ -0,0 +1,369 @@
#!/usr/bin/env python3
"""Renders an ab_session.py session into the markdown tables the report needs.
Separate from the runner on purpose: the runner's job is to COLLECT, and a renderer that is reading
its own session-summary.json cannot influence what was collected. Every number below is a lookup or
an arithmetic step over that file - nothing here re-derives anything from the device.
Usage:
python render_ab.py <session-dir>/session-summary.json [--title T]
"""
from __future__ import annotations
import argparse
import json
import sys
from pathlib import Path
def fmt(value, digits=3):
if value is None:
return "-"
if isinstance(value, float):
return f"{value:.{digits}f}"
return str(value)
def steady_state_cpu(arm):
"""Per-thread CPU ms/frame over the arm's steady-state frames, from the DEVICE's own two
independent series.
WHY NOT the sampler's totals divided by the frame count, which is what this used to report:
those totals are correct and the per-frame ratio is wrong, because a replay's frames are not
interchangeable. Measured on the rd12 fixture with this build, frame 1 costs 7332 ms of CPU on
the client thread - one shader/pipeline bring-up - and the other 250 frames cost 7.7-8.5 ms
each. Dividing a whole replay's CPU by 251 frames charges every frame 1/251st of a compile that
happened once, which is why that column read ~32 ms/frame beside a device median of 7.9. It is
a real number and not a real per-frame cost.
So the per-frame figures come from the two series the DEVICE already computes over the trailing
`tailFrames`:
- `medianFrameCpuMs` / `p95FrameCpuMs`: the client thread's own `clock_gettime(CLOCK_THREAD_
CPUTIME_ID)` deltas per frame, summarised over the tail. Host-side per-frame sampling cannot
reproduce this - a 0.5 s poll interval cannot resolve an 8 ms frame - and it is the primary
metric (MEASUREMENTS.md section 9).
- `medianFrameMs` / `p95FrameMs`: wall time per frame, which is what the frame budget is.
The sampler's contribution is the ROLES: which thread carried the work, on which core, and how
much CPU each role spent in total, which is what the doorbell comparison needs and what the
device's single client-thread series cannot express.
"""
best = arm.get("best_repeat") or {}
return {
"median_frame_ms": best.get("medianFrameMs"),
"p95_frame_ms": best.get("p95FrameMs"),
"median_frame_cpu_ms": best.get("medianFrameCpuMs"),
"p95_frame_cpu_ms": best.get("p95FrameCpuMs"),
"mean_frame_cpu_ms": best.get("meanFrameCpuMs"),
"fps": best.get("fps"),
}
def role_totals(arm):
"""(client cpu_ms, server cpu_ms) summed over the best repeat's window, and the window length.
TOTALS, not rates. They answer "which role spent the CPU and how much core-time did it burn",
and they are directly comparable across arms because every arm here replays the same fixture
with the same frame count - the one thing that would break the comparison is a different frame
count, which `repeat_count_matches_windows` and the shared `totalFrames` both guard.
"""
index = (arm.get("best_repeat") or {}).get("index", 1) - 1
repeats = arm.get("sampler", {}).get("per_repeat", [])
if not (0 <= index < len(repeats)):
return None, None, None
repeat = repeats[index]
client = server = 0.0
seen_c = seen_s = False
for thread in repeat.get("cpu", {}).get("threads", []):
if not thread.get("measurable") or thread.get("cpu_ms", 0) <= 0:
continue
role = thread.get("role")
if role == "client-gl":
client += thread["cpu_ms"]
seen_c = True
elif role in ("apply", "server-process"):
server += thread["cpu_ms"]
seen_s = True
return (client if seen_c else None, server if seen_s else None,
repeat.get("cpu", {}).get("window_seconds"))
def per_repeat_rows(arm):
"""One row per REPLAY, with the frame count taken from the matching benchmark run.
The CPU windows and the benchmark.json files are two independent records of the same repeats, in
the same order, and they are joined BY ORDINAL - window N is repeat N. The ordinal is asserted
rather than assumed (`repeat_count_matches_windows` in the arm summary): a mismatch means one
record has a replay the other does not, and silently pairing them would attribute one replay's
CPU to another replay's frames.
"""
runs = arm.get("benchmark_runs") or []
rows = []
for repeat in arm.get("sampler", {}).get("per_repeat", []):
client = server = 0.0
seen_c = seen_s = False
for thread in repeat.get("cpu", {}).get("threads", []):
if not thread.get("measurable") or thread.get("cpu_ms", 0) <= 0:
continue
role = thread.get("role")
if role == "client-gl":
client += thread["cpu_ms"]
seen_c = True
elif role in ("apply", "server-process"):
server += thread["cpu_ms"]
seen_s = True
index = repeat.get("repeat", 0) - 1
report = runs[index] if 0 <= index < len(runs) else {}
rows.append({
"repeat": repeat.get("repeat"),
"frames": report.get("totalFrames"),
"mean_frame_ms": report.get("meanFrameMs"),
"median_frame_ms": report.get("medianFrameMs"),
"median_frame_cpu_ms": report.get("medianFrameCpuMs"),
"fps": report.get("fps"),
"seconds": repeat.get("cpu", {}).get("window_seconds"),
"client_total_ms": client if seen_c else None,
"server_total_ms": server if seen_s else None,
})
return rows
def best_frames(arm):
return arm.get("best_repeat_frames") or (arm.get("best_repeat") or {}).get("totalFrames")
def wait_delta(arm):
"""The wait ledger for the arm, as run totals plus a per-frame rate.
THE FOUR NUMBERS COME FROM TWO DIFFERENT LOGS ON A SPAWN ARM, and that is structural rather than
a collection gap. `srv`/`srvpark` are published by the server's own apply loop into the PipeStats
of the process it runs in, so:
- under `inproc` both roles are threads of one process, and the client log's line carries all
four;
- under `spawn` the apply thread lives in the SERVER process, so its pair is written to
`mobilegl.server.log` and the client's line prints `srv=0 srvpark=0`. PipeStats.h documents
that shape: a zero that means "another process" printed like a zero that means "never
waited". So the pair is read from the server log here and the zeros are NOT reported as
evidence that the server never waited.
`cli`/`clipark` are the client's own producer and are always in the client log.
The per-frame rate divides by the RUN frame count (`frames=`, the third field on that line) and
NOT by `window=`.
THOSE ARE TWO DIFFERENT DENOMINATORS AND ONLY ONE OF THEM IS RIGHT HERE. Everything in the
`bytes/f[...]`, `tex[...]` and `emit[...]` brackets is a WINDOW value (the last `window=` frames),
but the `wait[...]` bracket and the ring gauges above it are RUN TOTALS - PipeStats.h says so in
as many words beside the Gauge enum, because "a windowed difference of two counters published by
two threads at two different moments is not a quantity either of them ever held". Dividing a run
total by a window length inflates the rate by (run/window) - measured on a 128-frame OpenRA
replay that is 16x, which looks like a plausible number and is not one.
WHICH LOG SUPPLIES THE RUN FRAME COUNT DEPENDS ON THE TRANSPORT, and this is the second
structural asymmetry of the spawn shape. The frame counter is bumped by `PipeStats::OnPresent`,
which the backend calls on Present, and under `spawn` Present is applied in the SERVER process:
- `inproc`: one process. The client log carries the session's final line, emitted by
`PipeStats::Shutdown` at teardown, `frames=251`. The server log's own last line is at its
previous period boundary (`frames=240`) because the apply thread does not emit the
session-final one. So the client's number is the run.
- `spawn`: the client never presents, so its `frames=0 window=0`. That zero is structural - it
is the same shape as the `srv=0` zero - and dividing by it is undefined. The run's frame
count is the SERVER's `frames=251`.
So the denominator is the client's when it is non-zero, and the server's when it is not, and
`run_frames_source` records which one was used. Using one log's frames with the other log's
counters - the obvious thing to write - is the mistake this paragraph exists to prevent.
"""
stats = arm.get("stats") or {}
client = stats.get("client") or {}
server = stats.get("server") or {}
wait = dict(client.get("wait") or {})
source = "client-log"
if arm.get("transport") == "spawn":
server_wait = server.get("wait")
if server_wait:
# Replace the client log's structurally-zero server half with the server's own.
wait["srv"] = server_wait["srv"]
wait["srvpark"] = server_wait["srvpark"]
source = "client-log(cli) + server-log(srv)"
else:
source = "client-log only (no server-log summary line: srv NOT available)"
run_frames = client.get("run_frames")
run_frames_source = "client-log"
if not run_frames:
# The spawn shape: this process never presented, so it counted no frames.
run_frames = server.get("run_frames")
run_frames_source = "server-log (client frames=0: it never presents under spawn)"
out = {"source": source, "wait": wait or None, "run_frames": run_frames,
"run_frames_source": run_frames_source,
"client_run_frames": client.get("run_frames"),
"client_window_frames": client.get("window_frames"),
"server_run_frames": server.get("run_frames"),
"server_window_frames": server.get("window_frames")}
if wait and run_frames:
out["per_frame"] = {key: round(value / run_frames, 4) for key, value in wait.items()}
return out
def main():
parser = argparse.ArgumentParser()
parser.add_argument("session")
parser.add_argument("--title", default=None)
args = parser.parse_args()
session = json.loads(Path(args.session).read_text(encoding="utf-8"))
arms = session.get("arms", [])
lines = []
title = args.title or f"A/B session {session.get('label')}"
lines.append(f"## {title}")
lines.append("")
lines.append(f"- session directory: `{session.get('label')}`")
lines.append(f"- boot id: `{session.get('boot_id')}` "
f"(reboot-clean: {session.get('rebooted_clean')})")
lines.append(f"- package: `{session.get('package')}`")
lines.append(f"- APK sha256: `{session.get('apk_sha256')}`")
lines.append("")
# --- headline: frame time and per-thread CPU ------------------------------------------------
lines.append("### Frame time and per-thread CPU (best of N)")
lines.append("")
lines.append("The `frame cpu` column is the CLIENT thread's own per-frame CPU clock, summarised by the")
lines.append("device over the trailing `tailFrames` - the primary metric (MEASUREMENTS.md section 9).")
lines.append("`client total` / `server total` are the sampler's per-role CPU TOTALS over that repeat,")
lines.append("which includes the one-off shader bring-up frame; they are not per-frame rates. See")
lines.append("steady_state_cpu in this file.")
lines.append("")
lines.append("| arm | transport | status | frames | tail | mean ms | p50 ms | p95 ms | fps | frame cpu p50 ms | cpu p95 ms | client total ms | server total ms |")
lines.append("|---|---|---|---|---|---|---|---|---|---|---|---|---|")
for arm in arms:
best = arm.get("best_repeat") or {}
client_total, server_total, _window = role_totals(arm)
lines.append(
f"| {arm.get('label')} | {arm.get('transport')} | {arm.get('status')} "
f"| {fmt(best.get('totalFrames'))} | {fmt(best.get('tailFrames'))} "
f"| {fmt(best.get('meanFrameMs'))} | {fmt(best.get('medianFrameMs'))} "
f"| {fmt(best.get('p95FrameMs'))} | {fmt(best.get('fps'), 2)} "
f"| {fmt(best.get('medianFrameCpuMs'))} | {fmt(best.get('p95FrameCpuMs'))} "
f"| {fmt(client_total, 1)} | {fmt(server_total, 1)} |")
lines.append("")
# --- the pair deltas ------------------------------------------------------------------------
lines.append("### Paired deltas (inproc = A, spawn = B)")
lines.append("")
lines.append("| pair | metric | A | B | B - A | B/A - 1 |")
lines.append("|---|---|---|---|---|---|")
by_key = {}
for arm in arms:
by_key.setdefault((arm.get("case"), arm.get("backend"), arm.get("transport")), arm)
seen_pairs = set()
for (case, backend, _transport) in by_key:
if (case, backend) in seen_pairs:
continue
seen_pairs.add((case, backend))
a = by_key.get((case, backend, "inproc"))
b = by_key.get((case, backend, "spawn"))
if not a or not b:
continue
for metric, getter in (
("mean frame ms", lambda x: (x.get("best_repeat") or {}).get("meanFrameMs")),
("p50 frame ms", lambda x: (x.get("best_repeat") or {}).get("medianFrameMs")),
("p95 frame ms", lambda x: (x.get("best_repeat") or {}).get("p95FrameMs")),
("client frame cpu p50 ms", lambda x: (x.get("best_repeat") or {}).get("medianFrameCpuMs")),
("client frame cpu p95 ms", lambda x: (x.get("best_repeat") or {}).get("p95FrameCpuMs")),
("fps", lambda x: (x.get("best_repeat") or {}).get("fps")),
):
va, vb = getter(a), getter(b)
if va and vb:
lines.append(f"| {case}/{backend} | {metric} | {fmt(va)} | {fmt(vb)} "
f"| {fmt(vb - va)} | {fmt(vb / va - 1, 4)} |")
for label, index in (("client cpu total ms", 0), ("server cpu total ms", 1)):
va, vb = role_totals(a)[index], role_totals(b)[index]
if va and vb:
lines.append(f"| {case}/{backend} | {label} | {fmt(va, 1)} | {fmt(vb, 1)} "
f"| {fmt(vb - va, 1)} | {fmt(vb / va - 1, 4)} |")
lines.append("")
# --- the doorbell ledger --------------------------------------------------------------------
lines.append("### The wait ledger")
lines.append("")
lines.append("The `wait[...]` bracket and the ring gauges are RUN TOTALS, so these rates divide by the run's")
lines.append("frame count (`frames=`), not by the `window=` of the same line. See wait_delta. The `used`")
lines.append("column names the log the frame count came from: under `spawn` the client's own `frames=` is")
lines.append("**structurally 0**, because it never presents - present is applied in the server process.")
lines.append("")
lines.append("| arm | counters from | frames from | used frames | cli frames= | srv frames= | srv | srvpark | cli | clipark | srv/f | srvpark/f | cli/f | clipark/f |")
lines.append("|---|---|---|---|---|---|---|---|---|---|---|---|---|---|")
for arm in arms:
entry = wait_delta(arm)
wait = entry["wait"] or {}
per = entry.get("per_frame") or {}
lines.append(
f"| {arm.get('label')} | {entry['source']} | {entry['run_frames_source']} "
f"| {fmt(entry.get('run_frames'))} | {fmt(entry.get('client_run_frames'))} "
f"| {fmt(entry.get('server_run_frames'))} "
f"| {fmt(wait.get('srv'))} | {fmt(wait.get('srvpark'))} | {fmt(wait.get('cli'))} "
f"| {fmt(wait.get('clipark'))} | {fmt(per.get('srv'))} | {fmt(per.get('srvpark'))} "
f"| {fmt(per.get('cli'))} | {fmt(per.get('clipark'))} |")
lines.append("")
# --- per repeat -----------------------------------------------------------------------------
lines.append("### Per-repeat windows")
lines.append("")
for arm in arms:
lines.append(f"**{arm.get('label')}** (windows={arm.get('sampler', {}).get('windows')}, "
f"repeats={len(arm.get('benchmark_runs') or [])}, "
f"replay={arm.get('best_repeat', {}).get('meanFrameMs')})")
lines.append("")
lines.append("| repeat | frames | window s | p50 frame ms | frame cpu p50 ms | client total ms | server total ms |")
lines.append("|---|---|---|---|---|---|---|")
for row in per_repeat_rows(arm):
lines.append(f"| {fmt(row['repeat'])} | {fmt(row['frames'])} | {fmt(row['seconds'], 1)} "
f"| {fmt(row['median_frame_ms'])} | {fmt(row['median_frame_cpu_ms'])} "
f"| {fmt(row['client_total_ms'], 1)} | {fmt(row['server_total_ms'], 1)} |")
lines.append("")
# --- byte classes and records ---------------------------------------------------------------
lines.append("### Wire byte classes and record size (gate 8 items 2-3 input)")
lines.append("")
lines.append("| arm | role | window | frames | buf/f | tex/f | ubog/f | ubon/f | csob-blob/f | resid/f | vtxc/f | idxc/f | icmd/f | pmap/f | maxrec | maxcap |")
lines.append("|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|")
for arm in arms:
for role in ("client", "server"):
stats = (arm.get("stats") or {}).get(role)
if not stats:
continue
bytes_per_frame = stats.get("bytes_per_frame") or {}
lines.append(
f"| {arm.get('label')} | {role} | {fmt(stats.get('window_frames'))} "
f"| {fmt(stats.get('run_frames'))} "
f"| {fmt(bytes_per_frame.get('buf'))} | {fmt(bytes_per_frame.get('tex'))} "
f"| {fmt(bytes_per_frame.get('ubog'))} | {fmt(bytes_per_frame.get('ubon'))} "
f"| {fmt(bytes_per_frame.get('csob-blob'))} | {fmt(bytes_per_frame.get('resid'))} "
f"| {fmt(bytes_per_frame.get('vtxc'))} | {fmt(bytes_per_frame.get('idxc'))} "
f"| {fmt(bytes_per_frame.get('icmd'))} | {fmt(bytes_per_frame.get('pmap'))} "
f"| {fmt(stats.get('max_record_bytes'))} | {fmt(stats.get('max_record_cap'))} |")
lines.append("")
# --- arm proof ------------------------------------------------------------------------------
lines.append("### Arm proof and pin state")
lines.append("")
lines.append("| arm | pin before | pin after | server pid (spawn) | problems |")
lines.append("|---|---|---|---|---|")
for arm in arms:
problems = "; ".join(arm.get("problems") or []) or "none"
lines.append(f"| {arm.get('label')} | {fmt(arm.get('pin_before_rc'))} "
f"| {fmt(arm.get('pin_after_rc'))} | {fmt(arm.get('server_pid'))} "
f"| {problems} |")
lines.append("")
print("\n".join(lines))
return 0
if __name__ == "__main__":
sys.exit(main())
tools/device_bench/pin_device.sh
+28 -1
View File
@@ -70,6 +70,33 @@ case "$SERIAL" in
GPU_PINNED_FREQ=1100000000 # gpuclk is in Hz on kgsl, NOT kHz
GPU_FREQ_UNIT=Hz
;;
2f7cbe2e) # Redmi M332BF, same SoC as 35d0befa but a DIFFERENT board vendor lock
DEV_NAME="Redmi M332BF / SM8750 / Adreno 830v2"
GPU_STYLE=kgsl
# Read off THIS unit on 2026-09-22, then confirmed against a pinned window (pin written,
# every node read back equal to the pin, unpinned, every node back at the stock values
# recorded below). Same SM8750 as 35d0befa and the same policy ids, BUT THE STOCK RANGES
# DIFFER (policy6 max is 3072000 here vs 2841600 there) - which is exactly why copying the
# sibling row would have been wrong even though the two parts are the same silicon.
# Every write below needs root; the verify action re-reads all of them.
POLICIES="big:policy6:1958400:1017600:3072000 little:policy0:1555200:556800:2745600"
THERMAL_TYPE=cpuss-0-0 # thermal_zone13 on this boot; matched by type, never by number
KGSL=/sys/class/kgsl/kgsl-3d0
# THE ONE PLACE THIS DEVICE DIFFERS FROM 35d0befa'S ROW, AND IT IS MEASURED, NOT ASSUMED.
# Collapsing the kgsl pwrlevel range onto 0 does NOT reach 1100 MHz here: gpuclk reads
# 1050000000 and stays there across repeated samples, because this unit ships
# thermal_pwrlevel=1 permanently (it latches - writing 0 returns success and the node reads
# back 1) and max_gpuclk is read-only at 1050000000. devfreq's own max_freq also clamps to
# 1050000000. So the pin is "the fastest frequency this board will actually run", not "the
# top OPP in the table" - recorded as 1050 MHz so `check` compares against the truth.
# Consequence for the campaign, stated where the number is: absolute times from this device
# are NOT comparable with the 35d0befa rows taken while it could still reach 1100.
GPU_PIN_LEVEL=0 # pwrlevel 0 = the 1050 MHz ceiling this board enforces
GPU_STOCK_MIN_LEVEL=12
GPU_STOCK_MAX_LEVEL=0
GPU_PINNED_FREQ=1050000000 # gpuclk is in Hz on kgsl, NOT kHz
GPU_FREQ_UNIT=Hz
;;
3B159D009VZ00000) # Oppo PLG110 / ColorOS, MediaTek MT6993 (Dimensity 9500), Mali
DEV_NAME="Oppo PLG110 / MT6993 / Mali (gpufreqv2)"
GPU_STYLE=gpufreqv2
@@ -84,7 +111,7 @@ case "$SERIAL" in
;;
*)
echo "$0: unknown serial '$SERIAL'." >&2
echo "Known: 35d0befa (Xiaomi/Adreno830), 3B159D009VZ00000 (Oppo/Mali)." >&2
echo "Known: 35d0befa (Xiaomi/Adreno830), 2f7cbe2e (Redmi/Adreno830), 3B159D009VZ00000 (Oppo/Mali)." >&2
echo "Refusing to guess: the pin path differs per SoC and a wrong one fails silently." >&2
exit 64 ;;
esac
tools/trace_replay/run_android_retrace_local.py
+19
View File
@@ -44,6 +44,25 @@ BACKENDS = {
},
}
# The trace APK's application id, overridable so a development build can be installed BESIDE an
# existing trace install instead of replacing it.
#
# WHY IT IS NEEDED: `-Pmobilegl.applicationIdSuffix=<x>` is the only way to put two trace APKs on one
# device, and two APKs signed by different keys cannot share an id at all (`adb install -r` fails
# with INSTALL_FAILED_UPDATE_INCOMPATIBLE). A machine that already carries a trace install under the
# canonical id - signed by whichever key was current when it was made - otherwise has to have that
# install destroyed before an A/B can run, which is destructive and, on a shared bench, rude.
#
# ABSENT MEANS THE CANONICAL ID, so every existing caller keeps the behaviour it had. What the
# override does NOT change: the Activity class, the intent action, the extras, the on-device app dir
# and the arm-proof markers all stay identical, so the lane under test is the real lane. The one
# thing that must move with it is `--package` in the same command, because trace-replay-ci.sh drives
# `am start`, `run-as` and `force-stop` off it. tools/device_bench/p6/ab_session.py sets both.
_trace_package_override = __import__("os").environ.get("MOBILEGL_TRACE_PACKAGE", "").strip()
if _trace_package_override:
for _backend in BACKENDS.values():
_backend["package"] = _trace_package_override
CASES = load_trace_cases()