From 08e7c57489174cb13901412387b824efe2a32520 Mon Sep 17 00:00:00 2001 From: Claude Date: Tue, 28 Jul 2026 07:41:11 +0000 Subject: [PATCH] Instrument packet-loop wakeups and CPU time (#653) Routing system apps through the tun is suspected to cost battery through wakeup frequency rather than throughput, but there was no way to check that on a device: the only figures the app surfaced were session counts and MB/s, and MB/s is exactly the metric that stays low while background chatter keeps waking the loop. Add always-on counters to handle_events(): loop iterations, epoll_wait calls, wakeups vs. timeouts, polls capped to EPOLL_MIN_CHECK, ready events split by source, tun packets/bytes, wall time spent scanning sessions vs. dispatching events, and the loop thread's CPU time. CPU time comes from CLOCK_THREAD_CPUTIME_ID, so it excludes time blocked in epoll_wait and is comparable across runs of different lengths; it is sampled at most once a second (plus once at loop exit) because that clock is not served from the vDSO. The remaining per-iteration cost is a few relaxed atomic adds and three vDSO CLOCK_MONOTONIC reads. Attribute work per UID where the native side actually knows one: new sessions (handle_ip resolves the UID only for those) and session-socket events. A fixed 128-slot table counts overflow instead of evicting, so a full table degrades into "some traffic unattributed" rather than a skewed split. Java classifies UIDs as system or user from Rule.system, matching what the VPN builder excludes when system apps are not routed. The report is exposed through ServiceSinkhole.dump(), i.e. adb shell dumpsys, and a one-line summary goes to logcat whenever the loop stops. No new preference: a diagnostic nobody enables measures nothing, and an expert knob would collide with the philosophy in AGENTS.md section 4. docs/battery-packet-loop-measurement.md documents what is measured, the limits of per-UID attribution, how to run a routed vs. excluded comparison, and the trade-off that stays either way (excluding system apps is friendlier to battery but conflicts with "Block connections without VPN" and leaves trackers in system apps unblocked). Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01KbwdXJUvWYvzb1WmZJkkQZ --- AGENTS.md | 16 +- app/CMakeLists.txt | 1 + .../eu/faircode/netguard/PacketLoopStats.java | 288 ++++++++++++++++++ .../eu/faircode/netguard/ServiceSinkhole.java | 78 +++++ app/src/main/jni/netguard/ip.c | 14 + app/src/main/jni/netguard/loopstats.c | 145 +++++++++ app/src/main/jni/netguard/netguard.c | 58 ++++ app/src/main/jni/netguard/netguard.h | 70 +++++ app/src/main/jni/netguard/session.c | 47 +++ .../netguard/PacketLoopStatsTest.java | 187 ++++++++++++ docs/battery-packet-loop-measurement.md | 154 ++++++++++ 11 files changed, 1055 insertions(+), 3 deletions(-) create mode 100644 app/src/main/java/eu/faircode/netguard/PacketLoopStats.java create mode 100644 app/src/main/jni/netguard/loopstats.c create mode 100644 app/src/test/java/eu/faircode/netguard/PacketLoopStatsTest.java create mode 100644 docs/battery-packet-loop-measurement.md diff --git a/AGENTS.md b/AGENTS.md index dd86e61f..1e368269 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -4,11 +4,15 @@ This is the shared, tool-agnostic guide for anyone — human or AI agent — wor in this repository. It is the single source of truth for how to navigate, build, and reason about TrackerControl, plus the rationale used when triaging issues. -One document sits next to this one and stays authoritative for their own scope: +Two documents sit next to this one and stay authoritative for their own scope: - **[wgbridge-rs/README.md](wgbridge-rs/README.md)** — the Rust WireGuard bridge: architecture, the JNI API surface, and how to build/test the crate. Read it before touching anything under `wgbridge-rs/` or `net.kollnig.missioncontrol.wg*`. +- **[docs/battery-packet-loop-measurement.md](docs/battery-packet-loop-measurement.md)** + — the packet loop's wakeup/CPU counters: what they measure, how to read them + with `dumpsys`, and how to run a system-apps-routed vs. excluded comparison. + Read it before making a battery claim about the tun. --- @@ -57,6 +61,8 @@ wgbridge-rs/ Rust crate embedding gotatun (Mullvad WireGuard) - `WidgetAdmin.java` — pause/resume alarms (`INTENT_ON`). `ServiceTileMain.java` — Quick-Settings tile. `ReceiverAutostart.java` — boot/always-on restart. - `VpnRoutes.java` — the tun route set (RFC1918/CGNAT excludes). + - `PacketLoopStats.java` — parses/formats the native packet-loop wakeup and CPU + counters; surfaced via `ServiceSinkhole.dump()` (`adb shell dumpsys`). - Policy helpers: `InteractiveStatePolicy`, `NativeFailureRecoveryPolicy`, `NetworkReloadPolicy`, `VpnReplacementSequencer`. - **Tracker detection + TC UI** — `net.kollnig.missioncontrol`: @@ -75,7 +81,8 @@ wgbridge-rs/ Rust crate embedding gotatun (Mullvad WireGuard) `Tunnel`, `Protector`, `Logger`, `DnsRecorder`. Mirror of `wgbridge-rs`. - **Native C packet engine** — `app/src/main/jni/netguard/`: `netguard.c`, `session.c`, `ip.c`, `tcp.c`, `udp.c`, `icmp.c`, `dns.c` (plaintext DNS parse), - `tls.c` (SNI, research-only), `dhcp.c`, `pcap.c`. Built by `CMakeLists.txt`. + `tls.c` (SNI, research-only), `dhcp.c`, `pcap.c`, `loopstats.c` (packet-loop + wakeup/CPU counters). Built by `CMakeLists.txt`. - **Rust WireGuard bridge** — `wgbridge-rs/` (see its README): `jni_bindings.rs`, `tunnel.rs`, `config.rs` (UAPI), `dns.rs` (passive DNS inspection), `transport/` (socketpair + tun-fd transports), `keys.rs`, `callbacks.rs`. @@ -175,7 +182,10 @@ The non-negotiables that decide most changes: 3. **Battery is a first-class constraint.** Anything periodic must be gated off idle/screen-off. Do not make DoH a stronger default until its screen-off cost is profiled and fixed. Battery is also frequently mis-attributed to the - VPN UID — surface stats, don't re-investigate. + VPN UID — surface stats, don't re-investigate. The packet loop carries always-on + wakeup/CPU counters; read them with `dumpsys` rather than guessing from + throughput — see + [docs/battery-packet-loop-measurement.md](docs/battery-packet-loop-measurement.md). 4. **Attribution is global, not per-app** (the DNS table has no UID). Treat this as a known, deliberately-deferred limitation, not a bug to patch ad-hoc. diff --git a/app/CMakeLists.txt b/app/CMakeLists.txt index 9033f078..4908d1ec 100644 --- a/app/CMakeLists.txt +++ b/app/CMakeLists.txt @@ -19,6 +19,7 @@ add_library( netguard src/main/jni/netguard/dns.c src/main/jni/netguard/dhcp.c src/main/jni/netguard/pcap.c + src/main/jni/netguard/loopstats.c src/main/jni/netguard/util.c ) include_directories( src/main/jni/netguard/ ) diff --git a/app/src/main/java/eu/faircode/netguard/PacketLoopStats.java b/app/src/main/java/eu/faircode/netguard/PacketLoopStats.java new file mode 100644 index 00000000..6b263916 --- /dev/null +++ b/app/src/main/java/eu/faircode/netguard/PacketLoopStats.java @@ -0,0 +1,288 @@ +package eu.faircode.netguard; + +/* + This file is part of TrackerControl. + + TrackerControl is free software: you can redistribute it and/or modify + it under the terms of the GNU General Public License as published by + the Free Software Foundation, either version 3 of the License, or + (at your option) any later version. + + TrackerControl is distributed in the hope that it will be useful, + but WITHOUT ANY WARRANTY; without even the implied warranty of + MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + GNU General Public License for more details. + + You should have received a copy of the GNU General Public License + along with TrackerControl. If not, see . +*/ + +import java.util.ArrayList; +import java.util.Collections; +import java.util.Comparator; +import java.util.List; +import java.util.Locale; + +/** + * Parses and formats the native packet-loop counters exposed by + * {@code jni_get_loop_stats} (issue #653). + * + *

The question these counters answer is whether routing system apps through + * the tun costs battery through wakeup frequency rather than + * throughput. The primary figures are therefore wakeups per hour and the loop + * thread's CPU time per hour — never MB/s, which stays low while background + * chatter from Play Services and friends keeps waking the loop. + * + *

Deliberately free of Android dependencies so the arithmetic and the report + * layout are unit-testable on the JVM; callers supply UID metadata through + * {@link UidInfo}. + */ +public class PacketLoopStats { + // Index of each scalar in the long[] from the native side. + // Keep in sync with LOOP_STATS_SCALARS / the writer in netguard.c. + static final int SCALARS = 16; + + private static final int IDX_ELAPSED_MS = 0; + private static final int IDX_ITERATIONS = 1; + private static final int IDX_POLLS = 2; + private static final int IDX_WAKEUPS = 3; + private static final int IDX_TIMEOUTS = 4; + private static final int IDX_RECHECK_POLLS = 5; + private static final int IDX_EVENTS_TUN = 6; + private static final int IDX_EVENTS_SOCK = 7; + private static final int IDX_EVENTS_PIPE = 8; + private static final int IDX_TUN_PACKETS = 9; + private static final int IDX_TUN_BYTES = 10; + private static final int IDX_CPU_US = 11; + private static final int IDX_SCAN_US = 12; + private static final int IDX_DISPATCH_US = 13; + private static final int IDX_UID_OVERFLOW = 14; + private static final int IDX_UID_COUNT = 15; + + private static final long MS_PER_HOUR = 3600_000L; + + /** How many UIDs to name individually in the report. */ + private static final int TOP_UIDS = 10; + + /** Metadata the caller resolves per UID; the native side only knows numbers. */ + public interface UidInfo { + /** Human-readable label, e.g. an app name. May be null. */ + String label(int uid); + + /** Whether this UID belongs to a system app, per {@link Rule#system}. */ + boolean isSystem(int uid); + } + + public static final class UidStat { + public final int uid; + public final long sessions; + public final long events; + + UidStat(int uid, long sessions, long events) { + this.uid = uid; + this.sessions = sessions; + this.events = events; + } + + long total() { + return sessions + events; + } + } + + public final long elapsedMs; + public final long iterations; + public final long polls; + public final long wakeups; + public final long timeouts; + public final long recheckPolls; + public final long eventsTun; + public final long eventsSock; + public final long eventsPipe; + public final long tunPackets; + public final long tunBytes; + public final long cpuUs; + public final long scanUs; + public final long dispatchUs; + public final long uidOverflow; + public final List uids; + + private PacketLoopStats(long[] raw) { + this.elapsedMs = raw[IDX_ELAPSED_MS]; + this.iterations = raw[IDX_ITERATIONS]; + this.polls = raw[IDX_POLLS]; + this.wakeups = raw[IDX_WAKEUPS]; + this.timeouts = raw[IDX_TIMEOUTS]; + this.recheckPolls = raw[IDX_RECHECK_POLLS]; + this.eventsTun = raw[IDX_EVENTS_TUN]; + this.eventsSock = raw[IDX_EVENTS_SOCK]; + this.eventsPipe = raw[IDX_EVENTS_PIPE]; + this.tunPackets = raw[IDX_TUN_PACKETS]; + this.tunBytes = raw[IDX_TUN_BYTES]; + this.cpuUs = raw[IDX_CPU_US]; + this.scanUs = raw[IDX_SCAN_US]; + this.dispatchUs = raw[IDX_DISPATCH_US]; + this.uidOverflow = raw[IDX_UID_OVERFLOW]; + + List parsed = new ArrayList<>(); + // Trust the array length rather than the declared count: a truncated + // array must not throw while the caller is only trying to read stats. + int declared = (int) raw[IDX_UID_COUNT]; + int available = (raw.length - SCALARS) / 3; + int count = Math.min(Math.max(declared, 0), Math.max(available, 0)); + for (int i = 0; i < count; i++) { + int base = SCALARS + i * 3; + parsed.add(new UidStat((int) raw[base], raw[base + 1], raw[base + 2])); + } + this.uids = Collections.unmodifiableList(parsed); + } + + /** + * @param raw the array returned by {@code jni_get_loop_stats}, or null + * @return the parsed snapshot, or null when the native side returned + * nothing usable + */ + public static PacketLoopStats parse(long[] raw) { + if (raw == null || raw.length < SCALARS) + return null; + return new PacketLoopStats(raw); + } + + /** Wakeups per hour — the metric the battery hypothesis rests on. */ + public double wakeupsPerHour() { + return perHour(wakeups); + } + + /** Loop-thread CPU seconds burned per hour of wall-clock time. */ + public double cpuSecondsPerHour() { + return perHour(cpuUs) / 1_000_000d; + } + + private double perHour(long value) { + if (elapsedMs <= 0) + return 0d; + return value * (double) MS_PER_HOUR / elapsedMs; + } + + /** + * Renders the human-readable report. + * + * @param info resolves UID labels and system classification + * @param routingSystem current value of the {@code include_system_vpn} + * preference, recorded so a report is never read + * without knowing which arm of the comparison it is + */ + public String format(UidInfo info, boolean routingSystem) { + StringBuilder sb = new StringBuilder(); + sb.append("Packet loop (issue #653)\n"); + sb.append(String.format(Locale.ROOT, " system apps routed: %s\n", + routingSystem ? "yes" : "no")); + sb.append(String.format(Locale.ROOT, " measured over: %s\n", duration(elapsedMs))); + + if (elapsedMs <= 0) { + sb.append(" no measurement yet (packet loop not running)\n"); + return sb.toString(); + } + + sb.append(" wakeups: ").append(wakeups) + .append(String.format(Locale.ROOT, " (%.0f/h)", wakeupsPerHour())).append('\n'); + sb.append(" epoll timeouts: ").append(timeouts) + .append(String.format(Locale.ROOT, " (%.0f/h)", perHour(timeouts))).append('\n'); + sb.append(" loop iterations: ").append(iterations); + if (wakeups > 0) + sb.append(String.format(Locale.ROOT, " (%.1f per wakeup)", iterations / (double) wakeups)); + sb.append('\n'); + sb.append(" polls capped to 100 ms: ").append(recheckPolls).append('\n'); + sb.append(" events: tun ").append(eventsTun) + .append(", socket ").append(eventsSock) + .append(", pipe ").append(eventsPipe).append('\n'); + sb.append(" tun packets: ").append(tunPackets) + .append(String.format(Locale.ROOT, " (%.0f/h)", perHour(tunPackets))) + .append(", ").append(tunBytes).append(" bytes\n"); + sb.append(String.format(Locale.ROOT, " loop thread CPU: %.3f s (%.3f s/h)\n", + cpuUs / 1_000_000d, cpuSecondsPerHour())); + sb.append(String.format(Locale.ROOT, " wall time in loop: scan %.3f s, dispatch %.3f s\n", + scanUs / 1_000_000d, dispatchUs / 1_000_000d)); + if (wakeups > 0) + sb.append(String.format(Locale.ROOT, " CPU per wakeup: %.0f us\n", + cpuUs / (double) wakeups)); + + appendUidBreakdown(sb, info); + return sb.toString(); + } + + private void appendUidBreakdown(StringBuilder sb, UidInfo info) { + long systemSessions = 0; + long systemEvents = 0; + long userSessions = 0; + long userEvents = 0; + for (UidStat stat : uids) + if (info != null && info.isSystem(stat.uid)) { + systemSessions += stat.sessions; + systemEvents += stat.events; + } else { + userSessions += stat.sessions; + userEvents += stat.events; + } + + sb.append(" attributed to system apps: ").append(systemSessions) + .append(" sessions, ").append(systemEvents).append(" socket events\n"); + sb.append(" attributed to user apps: ").append(userSessions) + .append(" sessions, ").append(userEvents).append(" socket events\n"); + long attributed = systemSessions + systemEvents + userSessions + userEvents; + if (attributed > 0) { + double share = 100d * (systemSessions + systemEvents) / attributed; + sb.append(String.format(Locale.ROOT, " system share of attributed work: %.1f%%\n", + share)); + } + if (uidOverflow > 0) + sb.append(" UID table overflow (updates dropped): ").append(uidOverflow).append('\n'); + + List sorted = new ArrayList<>(uids); + Collections.sort(sorted, new Comparator() { + @Override + public int compare(UidStat a, UidStat b) { + int byTotal = Long.compare(b.total(), a.total()); + return byTotal != 0 ? byTotal : Integer.compare(a.uid, b.uid); + } + }); + + sb.append(" top UIDs (sessions + socket events):\n"); + if (sorted.isEmpty()) + sb.append(" none\n"); + int shown = 0; + for (UidStat stat : sorted) { + if (shown++ >= TOP_UIDS) + break; + String label = info == null ? null : info.label(stat.uid); + sb.append(String.format(Locale.ROOT, " uid %d %s%s: %d sessions, %d socket events\n", + stat.uid, + label == null || label.isEmpty() ? "?" : label, + info != null && info.isSystem(stat.uid) ? " [system]" : "", + stat.sessions, stat.events)); + } + if (sorted.size() > TOP_UIDS) + sb.append(" ... and ").append(sorted.size() - TOP_UIDS).append(" more\n"); + } + + /** One-line variant for logcat. */ + public String summary(boolean routingSystem) { + return String.format(Locale.ROOT, + "Packet loop: system routed=%b over %s, wakeups=%d (%.0f/h), " + + "iterations=%d, tun packets=%d, cpu=%.3fs (%.3fs/h)", + routingSystem, duration(elapsedMs), wakeups, wakeupsPerHour(), + iterations, tunPackets, cpuUs / 1_000_000d, cpuSecondsPerHour()); + } + + static String duration(long ms) { + if (ms <= 0) + return "0s"; + long seconds = ms / 1000; + long hours = seconds / 3600; + long minutes = (seconds % 3600) / 60; + if (hours > 0) + return String.format(Locale.ROOT, "%dh%02dm", hours, minutes); + if (minutes > 0) + return String.format(Locale.ROOT, "%dm%02ds", minutes, seconds % 60); + return seconds + "s"; + } +} diff --git a/app/src/main/java/eu/faircode/netguard/ServiceSinkhole.java b/app/src/main/java/eu/faircode/netguard/ServiceSinkhole.java index 0ff81506..fffedf3b 100644 --- a/app/src/main/java/eu/faircode/netguard/ServiceSinkhole.java +++ b/app/src/main/java/eu/faircode/netguard/ServiceSinkhole.java @@ -97,9 +97,11 @@ import java.io.BufferedReader; import java.io.File; +import java.io.FileDescriptor; import java.io.FileReader; import java.io.IOException; import java.io.InputStreamReader; +import java.io.PrintWriter; import java.net.Inet4Address; import java.net.Inet6Address; import java.net.InetAddress; @@ -185,6 +187,10 @@ public class ServiceSinkhole extends VpnService { private static final Map mapValidated = new ConcurrentHashMap<>(); private Map mapUidAllowed = new HashMap<>(); private Map mapUidKnown = new HashMap<>(); + // uid -> Rule.system, kept only so the packet-loop report (issue #653) can + // split its per-UID counters into system and user apps without asking the + // package manager again. + private final Map mapUidSystem = new HashMap<>(); private final Map> mapUidIPFilters = new HashMap<>(); private Map mapForward = new HashMap<>(); public static ReentrantReadWriteLock lock = new ReentrantReadWriteLock(true); @@ -276,6 +282,8 @@ public enum Command { private native int[] jni_get_stats(long context); + private native long[] jni_get_loop_stats(long context); + private static native void jni_pcap(String name, int record_size, int file_size); private native void jni_socks5(String addr, int port, String username, String password); @@ -1858,6 +1866,12 @@ private void stopNative(ParcelFileDescriptor vpn) { if (tunnelThread != null) { Log.i(TAG, "Stopping tunnel thread"); + // Read the packet-loop counters (issue #653) before jni_clear wipes + // the context, so every native run leaves its wakeup totals behind. + PacketLoopStats loopStats = getPacketLoopStats(); + if (loopStats != null) + Log.w(TAG, loopStats.summary(isRoutingSystemApps())); + jni_stop(jni_context); Thread thread = tunnelThread; @@ -1885,6 +1899,65 @@ private void stopNative(ParcelFileDescriptor vpn) { // path below. } + private boolean isRoutingSystemApps() { + return PreferenceManager.getDefaultSharedPreferences(this) + .getBoolean("include_system_vpn", false); + } + + private PacketLoopStats getPacketLoopStats() { + if (jni_context == 0) + return null; + try { + return PacketLoopStats.parse(jni_get_loop_stats(jni_context)); + } catch (Throwable ex) { + Log.e(TAG, ex.toString() + "\n" + Log.getStackTraceString(ex)); + return null; + } + } + + private PacketLoopStats.UidInfo getLoopStatsUidInfo() { + return new PacketLoopStats.UidInfo() { + @Override + public String label(int uid) { + List names = Util.getApplicationNames(uid, ServiceSinkhole.this); + return names.isEmpty() ? null : names.get(0); + } + + @Override + public boolean isSystem(int uid) { + lock.readLock().lock(); + try { + // Unknown UIDs (e.g. root, mediaserver) are not in the rule + // list; treating them as system matches how the VPN builder + // excludes them when system apps are not routed. + Boolean system = mapUidSystem.get(uid); + return system == null || system; + } finally { + lock.readLock().unlock(); + } + } + }; + } + + /** + * Exposes the packet-loop counters (issue #653) without adding a user-facing + * setting or a periodic sampler that would itself cost battery: + * {@code adb shell dumpsys activity service + * net.kollnig.missioncontrol/eu.faircode.netguard.ServiceSinkhole}. + */ + @Override + protected void dump(FileDescriptor fd, PrintWriter writer, String[] args) { + try { + PacketLoopStats stats = getPacketLoopStats(); + if (stats == null) + writer.println("Packet loop (issue #653): no native context"); + else + writer.print(stats.format(getLoopStatsUidInfo(), isRoutingSystemApps())); + } catch (Throwable ex) { + writer.println(ex.toString()); + } + } + private void updateWireGuardInteractiveState(boolean interactive) { SharedPreferences prefs = PreferenceManager.getDefaultSharedPreferences(ServiceSinkhole.this); boolean wgEnabled = prefs.getBoolean("wg_enabled", false); @@ -1904,6 +1977,7 @@ private void unprepare() { lock.writeLock().lock(); mapUidAllowed.clear(); mapUidKnown.clear(); + mapUidSystem.clear(); mapHostsBlocked.clear(); mapUidIPFilters.clear(); mapForward.clear(); @@ -1921,6 +1995,10 @@ private void prepareUidAllowed(List listAllowed, List listRule) { for (Rule rule : listRule) mapUidKnown.put(rule.uid, rule.uid); + mapUidSystem.clear(); + for (Rule rule : listRule) + mapUidSystem.put(rule.uid, rule.system); + lock.writeLock().unlock(); } diff --git a/app/src/main/jni/netguard/ip.c b/app/src/main/jni/netguard/ip.c index 3deb7336..c438a3a7 100644 --- a/app/src/main/jni/netguard/ip.c +++ b/app/src/main/jni/netguard/ip.c @@ -101,6 +101,9 @@ int check_tun(const struct arguments *args, return -1; } } else if (length > 0) { + loop_stats_add(&args->ctx->stats.tun_packets, 1); + loop_stats_add(&args->ctx->stats.tun_bytes, (uint64_t) length); + // Write pcap record if (pcap_file != NULL) write_pcap_rec(buffer, (size_t) length); @@ -335,6 +338,12 @@ void handle_ip(const struct arguments *args, uid = get_uid(version, protocol, saddr, sport, daddr, dport); else uid = get_uid_q(args, version, protocol, source, sport, dest, dport); + + // Attribute the new session to its UID (issue #653). This is the + // only point where the native side learns the UID of traffic coming + // out of the tun, so it is also the only per-app attribution we can + // record for the upstream direction. + loop_stats_uid_session(&args->ctx->stats, uid); } log_android(ANDROID_LOG_DEBUG, @@ -460,6 +469,11 @@ void handle_ip(const struct arguments *args, redirect = NULL; if (cur != NULL) { + // SNI research mode defers the decision for port 443 past the + // SYN, so the UID for these sessions is resolved here instead of + // in the new-session branch above. checkedHostname flips 0 -> 1 + // exactly once per session, which keeps the count comparable. + loop_stats_uid_session(&args->ctx->stats, uid); cur->tcp.checkedHostname = 1; // A blocked verdict on an established session must reset the // connection: dropping only this segment is undone by TCP diff --git a/app/src/main/jni/netguard/loopstats.c b/app/src/main/jni/netguard/loopstats.c new file mode 100644 index 00000000..5fc2f94d --- /dev/null +++ b/app/src/main/jni/netguard/loopstats.c @@ -0,0 +1,145 @@ +/* + This file is part of TrackerControl. + + TrackerControl is free software: you can redistribute it and/or modify + it under the terms of the GNU General Public License as published by + the Free Software Foundation, either version 3 of the License, or + (at your option) any later version. + + TrackerControl is distributed in the hope that it will be useful, + but WITHOUT ANY WARRANTY; without even the implied warranty of + MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + GNU General Public License for more details. + + You should have received a copy of the GNU General Public License + along with TrackerControl. If not, see . +*/ + +// Packet-loop instrumentation for issue #653: measure how often the packet loop +// is woken and how much CPU it burns, so that routing system apps through the +// tun can be compared against excluding them without guessing from throughput. + +#include "netguard.h" + +void loop_stats_reset(struct loop_stats *stats) { + // Only the counters are reset; ordering does not matter because the loop + // thread has not started (or has already stopped) when this runs. + atomic_store_explicit(&stats->started_ms, (uint64_t) get_ms(), memory_order_relaxed); + atomic_store_explicit(&stats->iterations, 0, memory_order_relaxed); + atomic_store_explicit(&stats->polls, 0, memory_order_relaxed); + atomic_store_explicit(&stats->wakeups, 0, memory_order_relaxed); + atomic_store_explicit(&stats->timeouts, 0, memory_order_relaxed); + atomic_store_explicit(&stats->recheck_polls, 0, memory_order_relaxed); + atomic_store_explicit(&stats->events_tun, 0, memory_order_relaxed); + atomic_store_explicit(&stats->events_sock, 0, memory_order_relaxed); + atomic_store_explicit(&stats->events_pipe, 0, memory_order_relaxed); + atomic_store_explicit(&stats->tun_packets, 0, memory_order_relaxed); + atomic_store_explicit(&stats->tun_bytes, 0, memory_order_relaxed); + atomic_store_explicit(&stats->cpu_us, 0, memory_order_relaxed); + atomic_store_explicit(&stats->scan_us, 0, memory_order_relaxed); + atomic_store_explicit(&stats->dispatch_us, 0, memory_order_relaxed); + atomic_store_explicit(&stats->uid_overflow, 0, memory_order_relaxed); + + for (int i = 0; i < LOOP_UID_SLOTS; i++) { + stats->uids[i].uid = LOOP_UID_FREE; + stats->uids[i].sessions = 0; + stats->uids[i].events = 0; + } +} + +void loop_stats_add(atomic_uint_least64_t *counter, uint64_t delta) { + atomic_fetch_add_explicit(counter, delta, memory_order_relaxed); +} + +uint64_t loop_stats_get(const atomic_uint_least64_t *counter) { + return atomic_load_explicit(counter, memory_order_relaxed); +} + +long long get_us() { + struct timespec ts; + clock_gettime(CLOCK_MONOTONIC, &ts); + return ts.tv_sec * 1000000LL + ts.tv_nsec / 1000LL; +} + +uint64_t get_thread_cpu_us() { + struct timespec ts; + if (clock_gettime(CLOCK_THREAD_CPUTIME_ID, &ts)) + return 0; + return (uint64_t) ts.tv_sec * 1000000ULL + (uint64_t) ts.tv_nsec / 1000ULL; +} + +// Linear probing over a fixed table. The table is small and the number of UIDs +// generating traffic on a device is smaller still, so a scan is cheaper than a +// hash; once full, further UIDs are counted as overflow rather than evicting +// existing entries (evictions would silently distort the comparison). +static struct loop_uid_stat *loop_stats_uid_slot(struct loop_stats *stats, jint uid) { + struct loop_uid_stat *free_slot = NULL; + for (int i = 0; i < LOOP_UID_SLOTS; i++) { + if (stats->uids[i].uid == uid) + return &stats->uids[i]; + if (free_slot == NULL && stats->uids[i].uid == LOOP_UID_FREE) + free_slot = &stats->uids[i]; + } + + if (free_slot == NULL) { + loop_stats_add(&stats->uid_overflow, 1); + return NULL; + } + + free_slot->uid = uid; + return free_slot; +} + +void loop_stats_uid_session(struct loop_stats *stats, jint uid) { + struct loop_uid_stat *slot = loop_stats_uid_slot(stats, uid); + if (slot != NULL) + slot->sessions++; +} + +void loop_stats_uid_event(struct loop_stats *stats, jint uid) { + struct loop_uid_stat *slot = loop_stats_uid_slot(stats, uid); + if (slot != NULL) + slot->events++; +} + +// Emitted when the packet loop stops so a measurement run leaves a record in +// logcat even if nothing polled jni_get_loop_stats() beforehand. Java produces +// the readable, per-app report; this is the fallback totals line. +// +// Must be called from the packet-loop thread: it takes the final +// CLOCK_THREAD_CPUTIME_ID sample, which is only meaningful on that thread. +void log_loop_stats(struct context *ctx) { + struct loop_stats *stats = &ctx->stats; + uint64_t iterations = loop_stats_get(&stats->iterations); + if (iterations == 0) + return; + + atomic_store_explicit(&stats->cpu_us, get_thread_cpu_us(), memory_order_relaxed); + + uint64_t started_ms = loop_stats_get(&stats->started_ms); + uint64_t elapsed_ms = (uint64_t) get_ms() - started_ms; + + log_android(ANDROID_LOG_WARN, + "Packet loop stats elapsed %llu ms iterations %llu polls %llu " + "wakeups %llu timeouts %llu recheck %llu " + "events tun %llu sock %llu pipe %llu " + "tun packets %llu bytes %llu " + "cpu %llu us scan %llu us dispatch %llu us uid overflow %llu", + // uint64_t is "unsigned long" on LP64 and "unsigned long long" on + // ILP32, so cast rather than relying on %llu matching either one. + (unsigned long long) elapsed_ms, + (unsigned long long) iterations, + (unsigned long long) loop_stats_get(&stats->polls), + (unsigned long long) loop_stats_get(&stats->wakeups), + (unsigned long long) loop_stats_get(&stats->timeouts), + (unsigned long long) loop_stats_get(&stats->recheck_polls), + (unsigned long long) loop_stats_get(&stats->events_tun), + (unsigned long long) loop_stats_get(&stats->events_sock), + (unsigned long long) loop_stats_get(&stats->events_pipe), + (unsigned long long) loop_stats_get(&stats->tun_packets), + (unsigned long long) loop_stats_get(&stats->tun_bytes), + (unsigned long long) loop_stats_get(&stats->cpu_us), + (unsigned long long) loop_stats_get(&stats->scan_us), + (unsigned long long) loop_stats_get(&stats->dispatch_us), + (unsigned long long) loop_stats_get(&stats->uid_overflow)); +} diff --git a/app/src/main/jni/netguard/netguard.c b/app/src/main/jni/netguard/netguard.c index 1f2c246b..bc49d7cc 100644 --- a/app/src/main/jni/netguard/netguard.c +++ b/app/src/main/jni/netguard/netguard.c @@ -188,6 +188,9 @@ Java_eu_faircode_netguard_ServiceSinkhole_jni_1start( max_tun_msg = 0; ctx->stopping = 0; ctx->tcp_mss_clamp = tcp_mss_clamp; + // Counters cover one native run, so a "system apps routed" run and a + // "system apps excluded" run are never mixed in the same totals. + loop_stats_reset(&ctx->stats); log_android(ANDROID_LOG_WARN, "Starting level %d tcp mss clamp %d", loglevel, tcp_mss_clamp); @@ -289,6 +292,61 @@ Java_eu_faircode_netguard_ServiceSinkhole_jni_1get_1stats( return jarray; } +// Packet-loop instrumentation (issue #653). Returns a flat long[]: LOOP_STATS_* +// scalars first, then one (uid, sessions, events) triple per attributed UID. +// PacketLoopStats on the Java side owns the index constants and the formatting. +JNIEXPORT jlongArray JNICALL +Java_eu_faircode_netguard_ServiceSinkhole_jni_1get_1loop_1stats( + JNIEnv *env, jobject instance, jlong context) { + struct context *ctx = (struct context *) context; + struct loop_stats *stats = &ctx->stats; + + // The UID table is only written with ctx->lock held, so take it to read a + // consistent snapshot. The scalars are relaxed atomics and need no lock. + if (pthread_mutex_lock(&ctx->lock)) + log_android(ANDROID_LOG_ERROR, "pthread_mutex_lock failed"); + + jint uid_count = 0; + for (int i = 0; i < LOOP_UID_SLOTS; i++) + if (stats->uids[i].uid != LOOP_UID_FREE) + uid_count++; + + jlong values[LOOP_STATS_SCALARS + 3 * LOOP_UID_SLOTS]; + uint64_t started_ms = loop_stats_get(&stats->started_ms); + values[0] = started_ms == 0 ? 0 : (jlong) ((uint64_t) get_ms() - started_ms); + values[1] = (jlong) loop_stats_get(&stats->iterations); + values[2] = (jlong) loop_stats_get(&stats->polls); + values[3] = (jlong) loop_stats_get(&stats->wakeups); + values[4] = (jlong) loop_stats_get(&stats->timeouts); + values[5] = (jlong) loop_stats_get(&stats->recheck_polls); + values[6] = (jlong) loop_stats_get(&stats->events_tun); + values[7] = (jlong) loop_stats_get(&stats->events_sock); + values[8] = (jlong) loop_stats_get(&stats->events_pipe); + values[9] = (jlong) loop_stats_get(&stats->tun_packets); + values[10] = (jlong) loop_stats_get(&stats->tun_bytes); + values[11] = (jlong) loop_stats_get(&stats->cpu_us); + values[12] = (jlong) loop_stats_get(&stats->scan_us); + values[13] = (jlong) loop_stats_get(&stats->dispatch_us); + values[14] = (jlong) loop_stats_get(&stats->uid_overflow); + values[15] = uid_count; + + jsize length = LOOP_STATS_SCALARS; + for (int i = 0; i < LOOP_UID_SLOTS; i++) + if (stats->uids[i].uid != LOOP_UID_FREE) { + values[length++] = stats->uids[i].uid; + values[length++] = (jlong) stats->uids[i].sessions; + values[length++] = (jlong) stats->uids[i].events; + } + + if (pthread_mutex_unlock(&ctx->lock)) + log_android(ANDROID_LOG_ERROR, "pthread_mutex_unlock failed"); + + jlongArray jarray = (*env)->NewLongArray(env, length); + if (jarray != NULL) + (*env)->SetLongArrayRegion(env, jarray, 0, length, values); + return jarray; +} + JNIEXPORT void JNICALL Java_eu_faircode_netguard_ServiceSinkhole_jni_1pcap( JNIEnv *env, jclass type, diff --git a/app/src/main/jni/netguard/netguard.h b/app/src/main/jni/netguard/netguard.h index 7ec615db..4d6c7d4d 100644 --- a/app/src/main/jni/netguard/netguard.h +++ b/app/src/main/jni/netguard/netguard.h @@ -32,6 +32,7 @@ #include #include +#include #define TAG "TrackerControl.JNI" @@ -87,6 +88,53 @@ #define SOCKS5_CONNECT 4 #define SOCKS5_CONNECTED 5 +// Packet-loop instrumentation (issue #653). The battery cost of routing system +// apps through the tun is expected to come from wakeup frequency, not from +// throughput, so the counters below measure how often handle_events() is woken +// and how much CPU it burns once awake - deliberately not MB/s. +// +// Counters are cheap (a relaxed atomic add, plus five vDSO clock reads per loop +// iteration) and always on: without them there is no way to compare +// "system apps routed" against "system apps excluded" on a real device. +// +// Per-UID attribution is only possible where the native side already knows the +// UID, i.e. when a session is created (handle_ip resolves the UID for new +// sessions only) and when a session socket becomes readable. Packets read from +// the tun for an *existing* session carry no UID, so tun_packets is a global +// total. See docs/battery-packet-loop-measurement.md. +#define LOOP_UID_SLOTS 128 + +struct loop_uid_stat { + jint uid; // LOOP_UID_FREE when unused + uint64_t sessions; // new-session decisions attributed to this UID + uint64_t events; // session-socket epoll events dispatched for this UID +}; + +#define LOOP_UID_FREE (-2) // -1 is a valid "unknown UID" from get_uid() + +// Number of leading scalars in the long[] returned by jni_get_loop_stats(). +// Keep in sync with PacketLoopStats.SCALARS. +#define LOOP_STATS_SCALARS 16 + +struct loop_stats { + atomic_uint_least64_t started_ms; // get_ms() when the loop started + atomic_uint_least64_t iterations; // loop body entries + atomic_uint_least64_t polls; // epoll_wait() calls + atomic_uint_least64_t wakeups; // epoll_wait() returned > 0 + atomic_uint_least64_t timeouts; // epoll_wait() returned 0 + atomic_uint_least64_t recheck_polls; // polls capped to EPOLL_MIN_CHECK + atomic_uint_least64_t events_tun; // epoll events on the tun fd + atomic_uint_least64_t events_sock; // epoll events on session sockets + atomic_uint_least64_t events_pipe; // epoll events on the stop pipe + atomic_uint_least64_t tun_packets; // packets read from the tun + atomic_uint_least64_t tun_bytes; // bytes read from the tun + atomic_uint_least64_t cpu_us; // CLOCK_THREAD_CPUTIME_ID of the loop thread + atomic_uint_least64_t scan_us; // wall time spent walking/checking sessions + atomic_uint_least64_t dispatch_us; // wall time spent handling epoll events + atomic_uint_least64_t uid_overflow; // updates dropped because the table is full + struct loop_uid_stat uids[LOOP_UID_SLOTS]; +}; + struct context { pthread_mutex_t lock; int pipefds[2]; @@ -94,6 +142,7 @@ struct context { int sdk; jboolean tcp_mss_clamp; struct ng_session *ng_session; + struct loop_stats stats; }; struct arguments { @@ -370,6 +419,27 @@ void check_allowed(const struct arguments *args); void clear(struct context *ctx); +// Packet-loop instrumentation, see struct loop_stats. + +void loop_stats_reset(struct loop_stats *stats); + +void loop_stats_add(atomic_uint_least64_t *counter, uint64_t delta); + +uint64_t loop_stats_get(const atomic_uint_least64_t *counter); + +long long get_us(); + +uint64_t get_thread_cpu_us(); + +// Both UID updates are called with ctx->lock held (handle_ip and the +// session-socket dispatch both run inside the locked region of handle_events). +void loop_stats_uid_session(struct loop_stats *stats, jint uid); + +void loop_stats_uid_event(struct loop_stats *stats, jint uid); + +// Call from the packet-loop thread only, see loopstats.c. +void log_loop_stats(struct context *ctx); + int check_icmp_session(const struct arguments *args, struct ng_session *s, int sessions, int maxsessions); diff --git a/app/src/main/jni/netguard/session.c b/app/src/main/jni/netguard/session.c index ba69f378..f97ed066 100644 --- a/app/src/main/jni/netguard/session.c +++ b/app/src/main/jni/netguard/session.c @@ -92,9 +92,14 @@ void *handle_events(void *a) { // Loop long long last_check = 0; + long long last_cpu_sample_us = 0; + struct loop_stats *stats = &args->ctx->stats; while (!args->ctx->stopping) { log_android(ANDROID_LOG_DEBUG, "Loop"); + long long iteration_start_us = get_us(); + loop_stats_add(&stats->iterations, 1); + int recheck = 0; int timeout = EPOLL_TIMEOUT; @@ -183,9 +188,21 @@ void *handle_events(void *a) { // Poll struct epoll_event ev[EPOLL_EVENTS]; + long long pre_wait_us = get_us(); + loop_stats_add(&stats->scan_us, (uint64_t) (pre_wait_us - iteration_start_us)); + loop_stats_add(&stats->polls, 1); + if (recheck) + loop_stats_add(&stats->recheck_polls, 1); + int ready = epoll_wait(epoll_fd, ev, EPOLL_EVENTS, recheck ? EPOLL_MIN_CHECK : timeout * 1000); + long long post_wait_us = get_us(); + if (ready > 0) + loop_stats_add(&stats->wakeups, 1); + else if (ready == 0) + loop_stats_add(&stats->timeouts, 1); + if (ready < 0) { int error = errno; if (error == EINTR) { @@ -212,6 +229,8 @@ void *handle_events(void *a) { for (int i = 0; i < ready; i++) { if (ev[i].data.ptr == &ev_pipe) { + loop_stats_add(&stats->events_pipe, 1); + // Check pipe uint8_t buffer[1]; if (read(args->ctx->pipefds[0], buffer, 1) < 0) @@ -221,6 +240,8 @@ void *handle_events(void *a) { log_android(ANDROID_LOG_WARN, "Read pipe"); } else if (ev[i].data.ptr == NULL) { + loop_stats_add(&stats->events_tun, 1); + // Check upstream log_android(ANDROID_LOG_DEBUG, "epoll ready %d/%d in %d out %d err %d hup %d", i, ready, @@ -250,6 +271,13 @@ void *handle_events(void *a) { ((struct ng_session *) ev[i].data.ptr)->socket); struct ng_session *session = (struct ng_session *) ev[i].data.ptr; + loop_stats_add(&stats->events_sock, 1); + loop_stats_uid_event(stats, + session->protocol == IPPROTO_UDP + ? session->udp.uid + : (session->protocol == IPPROTO_TCP + ? session->tcp.uid + : session->icmp.uid)); if (session->protocol == IPPROTO_ICMP || session->protocol == IPPROTO_ICMPV6) check_icmp_socket(args, &ev[i]); @@ -275,9 +303,28 @@ void *handle_events(void *a) { if (error) break; } + + // Wall time spent handling this wakeup, plus the loop thread's total CPU + // time. CLOCK_THREAD_CPUTIME_ID only advances while the thread runs, so + // it excludes the time blocked in epoll_wait() and is therefore the + // figure to compare across configurations. It has to be read on this + // thread: a reader thread cannot observe another thread's CPU clock. + long long body_end_us = get_us(); + loop_stats_add(&stats->dispatch_us, (uint64_t) (body_end_us - post_wait_us)); + + // Unlike CLOCK_MONOTONIC, CLOCK_THREAD_CPUTIME_ID is not served from the + // vDSO, so sampling it every iteration would add a syscall to the busiest + // path in the app. Once a second is ample for the per-hour rates this + // measurement is about; the final sample is taken in log_loop_stats(), + // which also runs on this thread. + if (body_end_us - last_cpu_sample_us > 1000000LL) { + last_cpu_sample_us = body_end_us; + atomic_store_explicit(&stats->cpu_us, get_thread_cpu_us(), memory_order_relaxed); + } } cleanup: + log_loop_stats(args->ctx); // Close epoll file if (epoll_fd >= 0 && close(epoll_fd)) log_android(ANDROID_LOG_ERROR, diff --git a/app/src/test/java/eu/faircode/netguard/PacketLoopStatsTest.java b/app/src/test/java/eu/faircode/netguard/PacketLoopStatsTest.java new file mode 100644 index 00000000..1a340874 --- /dev/null +++ b/app/src/test/java/eu/faircode/netguard/PacketLoopStatsTest.java @@ -0,0 +1,187 @@ +package eu.faircode.netguard; + +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertNotNull; +import static org.junit.Assert.assertNull; +import static org.junit.Assert.assertTrue; + +import org.junit.Test; + +import java.util.HashMap; +import java.util.Map; + +/** + * Covers the packet-loop measurement plumbing for issue #653: the wire format + * between the native counters and the report, the per-hour rates the comparison + * relies on, and the system/user split. + */ +public class PacketLoopStatsTest { + + private static final class FakeUidInfo implements PacketLoopStats.UidInfo { + final Map labels = new HashMap<>(); + final Map system = new HashMap<>(); + + @Override + public String label(int uid) { + return labels.get(uid); + } + + @Override + public boolean isSystem(int uid) { + Boolean value = system.get(uid); + return value != null && value; + } + } + + /** Builds the flat array the native side produces. */ + private static long[] raw(long elapsedMs, long wakeups, long cpuUs, long[]... uids) { + long[] out = new long[PacketLoopStats.SCALARS + uids.length * 3]; + out[0] = elapsedMs; + out[1] = wakeups * 2; // iterations + out[2] = wakeups * 2; // polls + out[3] = wakeups; + out[4] = 7; // timeouts + out[5] = 3; // recheck polls + out[6] = 11; // events tun + out[7] = 13; // events sock + out[8] = 0; // events pipe + out[9] = 17; // tun packets + out[10] = 4096; // tun bytes + out[11] = cpuUs; + out[12] = 500; // scan us + out[13] = 900; // dispatch us + out[14] = 0; // uid overflow + out[15] = uids.length; + for (int i = 0; i < uids.length; i++) + System.arraycopy(uids[i], 0, out, PacketLoopStats.SCALARS + i * 3, 3); + return out; + } + + @Test + public void parsesScalarsAndUidTriples() { + PacketLoopStats stats = PacketLoopStats.parse( + raw(60_000, 100, 250_000, new long[]{10123, 5, 40}, new long[]{10456, 2, 8})); + + assertNotNull(stats); + assertEquals(60_000, stats.elapsedMs); + assertEquals(100, stats.wakeups); + assertEquals(200, stats.iterations); + assertEquals(7, stats.timeouts); + assertEquals(3, stats.recheckPolls); + assertEquals(11, stats.eventsTun); + assertEquals(13, stats.eventsSock); + assertEquals(17, stats.tunPackets); + assertEquals(4096, stats.tunBytes); + assertEquals(250_000, stats.cpuUs); + assertEquals(2, stats.uids.size()); + assertEquals(10123, stats.uids.get(0).uid); + assertEquals(5, stats.uids.get(0).sessions); + assertEquals(40, stats.uids.get(0).events); + } + + @Test + public void rejectsMissingOrTruncatedInput() { + assertNull(PacketLoopStats.parse(null)); + assertNull(PacketLoopStats.parse(new long[0])); + assertNull(PacketLoopStats.parse(new long[PacketLoopStats.SCALARS - 1])); + } + + @Test + public void ignoresUidEntriesTheArrayDoesNotActuallyContain() { + // A declared count larger than the payload must not throw: reading stats + // is diagnostics and may never take the service down. + long[] input = raw(60_000, 10, 1_000); + input[15] = 5; + + PacketLoopStats stats = PacketLoopStats.parse(input); + assertNotNull(stats); + assertTrue(stats.uids.isEmpty()); + } + + @Test + public void ratesAreScaledToOneHour() { + PacketLoopStats stats = PacketLoopStats.parse(raw(1_800_000, 900, 30_000_000)); + + assertNotNull(stats); + assertEquals(1800d, stats.wakeupsPerHour(), 0.001); + assertEquals(60d, stats.cpuSecondsPerHour(), 0.001); + } + + @Test + public void ratesAreZeroBeforeTheLoopHasRun() { + PacketLoopStats stats = PacketLoopStats.parse(raw(0, 0, 0)); + + assertNotNull(stats); + assertEquals(0d, stats.wakeupsPerHour(), 0.0); + assertEquals(0d, stats.cpuSecondsPerHour(), 0.0); + assertTrue(stats.format(null, false).contains("no measurement yet")); + } + + @Test + public void reportSplitsSystemFromUserApps() { + FakeUidInfo info = new FakeUidInfo(); + info.labels.put(10123, "Google Play Store"); + info.system.put(10123, true); + info.labels.put(10456, "Some App"); + info.system.put(10456, false); + + PacketLoopStats stats = PacketLoopStats.parse( + raw(3_600_000, 400, 8_000_000, + new long[]{10123, 30, 270}, + new long[]{10456, 10, 90})); + + assertNotNull(stats); + String report = stats.format(info, true); + assertTrue(report.contains("system apps routed: yes")); + assertTrue(report.contains("attributed to system apps: 30 sessions, 270 socket events")); + assertTrue(report.contains("attributed to user apps: 10 sessions, 90 socket events")); + assertTrue(report.contains("system share of attributed work: 75.0%")); + assertTrue(report.contains("Google Play Store [system]")); + assertTrue(report.contains("wakeups: 400 (400/h)")); + } + + @Test + public void reportOrdersUidsByTotalWork() { + FakeUidInfo info = new FakeUidInfo(); + PacketLoopStats stats = PacketLoopStats.parse( + raw(60_000, 10, 1_000, + new long[]{10001, 1, 1}, + new long[]{10002, 50, 50})); + + assertNotNull(stats); + String report = stats.format(info, false); + assertTrue(report.indexOf("uid 10002") < report.indexOf("uid 10001")); + assertTrue(report.contains("system apps routed: no")); + } + + @Test + public void reportFlagsUidTableOverflow() { + long[] input = raw(60_000, 10, 1_000); + input[14] = 42; + + PacketLoopStats stats = PacketLoopStats.parse(input); + assertNotNull(stats); + assertTrue(stats.format(null, false) + .contains("UID table overflow (updates dropped): 42")); + } + + @Test + public void summaryIsOneLineAndNamesTheArm() { + PacketLoopStats stats = PacketLoopStats.parse(raw(7_200_000, 1_000, 20_000_000)); + + assertNotNull(stats); + String summary = stats.summary(true); + assertEquals(-1, summary.indexOf('\n')); + assertTrue(summary.contains("system routed=true")); + assertTrue(summary.contains("over 2h00m")); + assertTrue(summary.contains("wakeups=1000 (500/h)")); + } + + @Test + public void formatsDurations() { + assertEquals("0s", PacketLoopStats.duration(0)); + assertEquals("45s", PacketLoopStats.duration(45_000)); + assertEquals("5m30s", PacketLoopStats.duration(330_000)); + assertEquals("3h05m", PacketLoopStats.duration(11_100_000)); + } +} diff --git a/docs/battery-packet-loop-measurement.md b/docs/battery-packet-loop-measurement.md new file mode 100644 index 00000000..3411b549 --- /dev/null +++ b/docs/battery-packet-loop-measurement.md @@ -0,0 +1,154 @@ +# Measuring the battery cost of routing system apps (issue #653) + +Routing system apps through TrackerControl's tun (the **Monitor system apps** +setting, `include_system_vpn`) has always been reported as costly for battery, +and that is why it is off by default. The working hypothesis is that the cost is +**wakeup frequency**, not tunnel throughput: background chatter from Play Store, +Play Services, carrier services and friends crosses the tun constantly, and each +crossing wakes the native packet loop. + +Throughput (MB/s) is the wrong metric for that hypothesis. A few hundred bytes +per minute can still wake the loop hundreds of times per hour, and it is the +wakeups — not the bytes — that keep the CPU out of deep idle. This document +describes the counters the app now records and how to run the comparison. + +## What is instrumented + +`handle_events()` in `app/src/main/jni/netguard/session.c` is the packet loop: +it walks the session list, computes an epoll timeout, blocks in `epoll_wait()`, +and dispatches whatever became ready. `struct loop_stats` +(`app/src/main/jni/netguard/netguard.h`, implemented in `loopstats.c`) records: + +| Counter | Meaning | +| --- | --- | +| `iterations` | loop body entries | +| `polls` | `epoll_wait()` calls | +| `wakeups` | `epoll_wait()` returned at least one ready fd — **the primary metric** | +| `timeouts` | `epoll_wait()` returned 0 (the loop woke on its own timeout) | +| `recheck_polls` | polls whose timeout was capped to `EPOLL_MIN_CHECK` (100 ms) | +| `events_tun` / `events_sock` / `events_pipe` | ready events by source | +| `tun_packets` / `tun_bytes` | packets and bytes read from the tun | +| `cpu_us` | `CLOCK_THREAD_CPUTIME_ID` of the loop thread — **the second primary metric** | +| `scan_us` / `dispatch_us` | wall time walking/checking sessions vs. handling events | +| per-UID `sessions` / `events` | attribution, see the caveat below | + +`cpu_us` is read on the loop thread itself, because a thread's CPU clock is not +observable from another thread. It only advances while the thread actually runs, +so it already excludes time blocked in `epoll_wait()` — that makes it directly +comparable between configurations regardless of how long the run was. It is +sampled at most once a second (plus once when the loop stops), because +`CLOCK_THREAD_CPUTIME_ID` is not served from the vDSO and per-iteration sampling +would add a syscall to the app's busiest path; at hour scale the throttling is +invisible. + +The counters are always on. Their per-iteration cost is a handful of relaxed +atomic adds and three vDSO `CLOCK_MONOTONIC` reads — orders of magnitude below +the `epoll_wait()` syscall they accompany. There is no preference to enable them, +because a diagnostic nobody turns on measures nothing, and a new expert knob +would collide with the philosophy in `AGENTS.md` §4. + +Counters are reset in `jni_start`, i.e. per native run. A `reload()` does a +native restart, so a run ends whenever the network changes, the screen-off delay +fires, or a setting changes — see "reading the numbers" below. + +### Per-UID attribution and its limits + +The native side only learns a packet's UID when it resolves one, which +`handle_ip()` does **for new sessions only** (a TCP SYN, a new UDP flow, ICMP). +Subsequent packets of an established session carry no UID, so: + +- `sessions` per UID counts new-session decisions — a good proxy for "who keeps + opening connections", which is what background chatter looks like. +- `events` per UID counts session-socket epoll events, taken from the session + that owns the socket, so the downstream direction is attributed per app. +- `tun_packets` is a **global** total and cannot be split per app. + +The table holds `LOOP_UID_SLOTS` (128) UIDs. Once full, further UIDs increment +`uid_overflow` rather than evicting entries, so a full table degrades into +"some traffic is unattributed" instead of silently skewing the split. The report +prints `uid_overflow` whenever it is non-zero; treat any non-zero value as a +reason to distrust the system/user split in that run. + +System-vs-user classification happens on the Java side from `Rule.system` +(cached in `ServiceSinkhole.mapUidSystem`), so it matches exactly the +classification the VPN builder uses when it excludes system apps. UIDs that are +not in the rule list at all (root, mediaserver, the DNS daemon) are counted as +system, again matching what the builder excludes. + +## Reading the numbers + +```bash +adb shell dumpsys activity service \ + net.kollnig.missioncontrol/eu.faircode.netguard.ServiceSinkhole +``` + +For the debug build, use the suffixed application id: + +```bash +adb shell dumpsys activity service \ + net.kollnig.missioncontrol.test/eu.faircode.netguard.ServiceSinkhole +``` + +This prints elapsed time, per-hour rates, the system/user split and the top +UIDs. `dumpsys` costs nothing when nobody calls it, which is why the report is +exposed there rather than through a periodic sampler or a UI screen. + +A one-line summary is also written to logcat every time the packet loop stops, +so a measurement run is not lost if the VPN restarts before anyone polls: + +```bash +adb logcat -s TrackerControl.VPN TrackerControl.JNI | grep "Packet loop" +``` + +`TrackerControl.VPN` carries the Java one-liner (with the routing arm named); +`TrackerControl.JNI` carries the raw native totals, which survive even if the +Java side never got a chance to read them. + +Because counters reset per native run, prefer `dumpsys` at the end of a long +undisturbed window over summing logcat lines; if you do sum logcat lines, sum +`wakeups` and `cpu` and sum the elapsed times too, and derive the rate from the +totals rather than averaging the per-run rates. + +## Running the comparison + +The confound to beat is usage: two days are never equally busy, so raw totals +from an A/B across days say little. In order of increasing confidence: + +1. **Within one run.** Turn Monitor system apps on and read the system share of + attributed work. This needs no second run and is not confounded by usage, + but it only covers session and socket-event attribution (see the caveat). +2. **A/B with the screen off and the device idle.** Charge to the same level, + leave the device untouched and screen-off for the same duration (2 h+ each), + once with the setting on and once off. Compare `wakeups/h` and + `cpu s/h`. Idle windows are far more comparable than active ones, and idle is + exactly where a wakeup-driven cost matters. +3. **Correlate with platform accounting.** `adb shell dumpsys batterystats + --charged net.kollnig.missioncontrol` for the same window. Note that battery + blamed on the VPN UID is routinely traffic *caused* by other apps and merely + *attributed* to the tunnel — `AGENTS.md` §4 constraint 3. The point of + `cpu_us` is to have a figure that is not subject to that mis-attribution. + +Keep `wg_enabled` and the blocking mode fixed across the arms of a comparison. +WireGuard changes the packet path (packets are handed to the bridge instead of +running through the userspace TCP/UDP state machines) and the blocking mode +changes how many hosts are resolved, so both move the counters. + +Report each arm as: duration, `wakeups/h`, `cpu s/h`, `tun packets/h`, and the +system share. Do not report MB/s as the headline. + +## The trade-off to preserve + +Excluding system apps is friendlier to battery, but it is not free: + +- Android's **Block connections without VPN** ("always-on VPN" lockdown) drops + traffic from apps the VPN does not route. With system apps excluded, enabling + lockdown breaks them, which is why the setting's summary tells users lockdown + must stay disabled. +- Trackers embedded in system apps are neither detected nor blocked while those + apps bypass the tun. + +Whatever the measurement concludes, that trade-off stays: the outcome should be +a better-informed default and a clearer explanation, not a new expert knob. The +user-facing surface is a single **Monitor system apps** switch that drives +`include_system_vpn`, `manage_system` and `show_system` together +(`ActivitySettings.onSharedPreferenceChanged`), and it should stay one switch.