% logging-signposts-power.tex — unified logging (Logger, levels + persistence,
% privacy/redaction, reading: Xcode console, Console.app, log stream/show,
% OSLogStore), signposts (OSSignposter intervals/events, Points of Interest,
% one track per name in Xcode 27), CI (xctrace, XCTOSSignpostMetric), energy
% (CPU/network/location/display), Power Profiler (Xcode 26, .atrc), field data
% (MetricKit payloads, mxSignpost; Organizer incl. Xcode 27 Hitches/Storage/
% Insights/goals).
% Sources (checked 2026-09-25): developer.apple.com "Generating log messages from
% your code" (level/persistence table, redaction defaults); Xcode 26 + 27 release
% notes (Power Profiler, .atrc, xctrace run-name / recording-options / export,
% os_signpost track per name, Organizer Hitches/Storage/Insights/goals); WWDC25
% 226 "Profile and optimize power usage in your app" (CPU/GPU/display/networking
% lanes, passive recording from Developer settings); WWDC19 417 (hang rate in
% seconds per hour); research-swift-xcode-2026-09-25.md.
% Not repeated: Instruments workflow / Time Profiler / Hangs (ios-swift/instruments-performance),
% MXDiagnosticPayload crash handling (security-build/crashes-symbolication).
% Build ONLY with: tools/print/print-sheet.py <this>.tex --dry-run
% @source: hiot monorepo, docs/school/sheets/debugging/logging-signposts-power.tex — the SOURCE OF TRUTH; a copy anywhere else (e.g. artur.gurgul.pro) is regenerated from it, never edited
% @labels: area=debugging kind=tooling level=senior platform=apple new=no round=market-2026-09-25 topic=debugging,performance
% @tags: oslog, logger, log-levels, log-privacy, ossignposter, points-of-interest, xctrace, power-profiler, energy, metrickit, mxsignpost, xcode-organizer
\documentclass[8pt]{extarticle}
\usepackage{printup-sheet}
\usepackage{array}

\lstdefinelanguage{SwiftSheet}{
  morekeywords={import,extension,static,let,var,func,defer,self,private,struct,
    class,final,return,true,false},
  sensitive=true, morecomment=[l]{//}, morestring=[b]",
  literate={==}{{\hbox{=}\hbox{=}}}2 {->}{{\hbox{-}\hbox{>}}}2 {??}{{\hbox{?}\hbox{?}}}2}
\lstdefinelanguage{ShSheet}{
  morekeywords={log,xcrun,xctrace,stream,show,record,export},
  sensitive=true, morecomment=[l]{\#}, morestring=[b]',
  literate={--}{{\hbox{-}\hbox{-}}}2 {==}{{\hbox{=}\hbox{=}}}2}
\lstset{basicstyle=\ttfamily\footnotesize, aboveskip=2pt, belowskip=2pt}

\newcommand\ct[1]{\texttt{#1}}
\newcommand\dd{\hbox{-}\hbox{-}}

\tikzset{
  col/.style={box, font=\scriptsize, align=left, inner sep=2pt, anchor=north},
  hd/.style={font=\bfseries\small, anchor=south},
  lbl/.style={font=\tiny, text=black!75, inner sep=1pt, align=center},
  lv/.style={cell, font=\ttfamily\tiny, minimum width=9.5mm, minimum height=4mm},
}

\begin{document}

\sheettitle{Logging, signposts \& power — from code to field data}{debugging · memo}

\oneliner{\textbf{\ct{Logger}} writes \emph{words} into the OS's unified log
(cheap, levelled, private by default), \textbf{\ct{OSSignposter}} writes
\emph{time} (intervals and events Instruments draws as tracks), and the OS itself
measures \emph{energy}. Read it live (Xcode console, Console, \ct{log}),
recorded (Instruments, Power Profiler, \ct{xctrace}), or aggregated from users
(MetricKit, Organizer).}

\vspace{2pt}
\noindent\begin{tikzpicture}[sheet]
  % ── code ──
  \node[hd, text=sheetBlue] at (1.6,0.05) {1 your code};
  \node[col, text width=30mm, minimum height=25mm] (code) at (1.6,0) {%
    \ct{Logger(subsystem:category:)}\\\ \ \ct{.debug .info .notice}\\\ \ \ct{.error .fault}\\[2pt]
    \ct{OSSignposter}\\\ \ \ct{beginInterval / endInterval}\\\ \ \ct{emitEvent}\\[2pt]
    \ct{mxSignpost(…)} (MetricKit)};
  % ── OS store ──
  \node[hd, text=sheetBrown] at (6.05,0.05) {2 the OS};
  \node[col, draw=sheetBrown, fill=sheetBrown!6, text width=40mm, minimum height=25mm] (os) at (6.05,0) {};
  \node[font=\scriptsize, anchor=north west, align=left] at (4.0,-0.08) {unified log: binary, formatted \emph{on read}};
  \foreach \t/\f/\x in {debug/sheetRed!12/4.55, info/sheetOrange!15/5.5, notice/sheetGreen!15/6.45, error/sheetGreen!15/7.4}
    \node[lv, fill=\f] at (\x,-0.72) {\t};
  \node[lv, fill=sheetGreen!15] at (7.4,-1.14) {fault};
  \node[lbl, anchor=west, align=left] at (3.98,-1.24) {\textcolor{sheetRed}{debug}: never on disk\\\textcolor{sheetOrange}{info}: only if collected};
  \node[lbl, anchor=north west, align=left] at (3.98,-1.62) {notice/error/fault: disk, up to a limit\\signpost stream · power + thermal telemetry\\daily MetricKit aggregation (on device)};
  % ── desk tools ──
  \node[hd, text=sheetGreen!55!black] at (11.0,0.05) {3a on your desk (dev)};
  \node[col, draw=sheetGreen!70!black, fill=sheetGreen!8, text width=40mm, minimum height=13mm] (desk) at (11.0,0) {%
    Xcode console (structured, filter, jump to line)\\
    Console.app · \ct{log stream / show} · sysdiagnose\\
    Instruments: \textbf{os\_signpost}, \textbf{Points of Interest},\\\textbf{Power Profiler} (\ct{.atrc}) · \ct{xctrace} in CI};
  % ── field tools ──
  \node[hd, text=sheetOrange, anchor=north] at (11.0,-1.35) {3b from users (field)};
  \node[col, draw=sheetOrange, fill=sheetOrange!8, text width=40mm, minimum height=10mm] (field) at (11.0,-1.7) {%
    \textbf{MetricKit}: your subscriber, per device, daily\\
    \textbf{Organizer}: Apple-aggregated, opt-in users —\\Hitches · Storage · Insights · goals (Xcode 27)};
  \draw[hot] (code.east) -- (os.west);
  \draw[flow] (os.east) -- ++(0.25,0) |- (desk.west);
  \draw[flow] (os.east) -- ++(0.25,0) |- (field.west);
  \node[lbl, anchor=north west, align=left] at (13.15,-0.02) {live /\\recorded};
  \node[lbl, anchor=north west, align=left] at (13.15,-1.72) {aggregated,\\a day late};
\end{tikzpicture}

\begin{multicols}{2}
\small\setstretch{1.0}\raggedright

\section{Unified logging — how it works}
\begin{itemize}
  \item \ct{Logger(subsystem: "com.acme.app", category: "network")} — subsystem =
        reverse-DNS app/module, category = component; both are filter keys.
  \item The message is stored \textbf{binary}: format string + arguments, rendered
        when someone reads it. Calling it is cheap; a disabled \ct{debug} is
        almost free. \ct{print} builds a string and only reaches stdout.
  \item \textbf{Levels} (Apple's table): \ct{debug} not persisted · \ct{info}
        persisted only when collected with the \ct{log} tool · \ct{notice}
        (default), \ct{error}, \ct{fault} persisted up to a storage limit;
        error/fault also capture the activity's process chain. Aliases:
        \ct{trace}=debug, \ct{warning}=error, \ct{critical}=fault.
  \item \textbf{Privacy}: interpolated ints, floats, bools are public; dynamic
        strings and objects are \textbf{redacted} (\ct{<private>} when no debugger
        is attached). Opt in per value: \ct{privacy: .public}, or
        \ct{.private(mask: .hash)} to correlate without revealing.
  \item \textbf{Read}: Xcode 15+ console is structured (level, subsystem,
        category, source line). Console.app: pick the device, \emph{Include
        Info/Debug Messages}. Field bugs: sysdiagnose, or read your own logs
        in-app with \ct{OSLogStore(scope: .currentProcessIdentifier)} and attach
        them to a report.
\end{itemize}

\section{Example}
\begin{lstlisting}[language=SwiftSheet]
import os
extension Logger {
  static let net = Logger(subsystem: "com.acme.app",
                          category: "network") }
Logger.net.info("GET \(url.path, privacy: .public)")
Logger.net.error("HTTP \(code) user \(uid,
                 privacy: .private(mask: .hash))")
let sp = OSSignposter(logger: .net)
func fetch() async throws -> Feed {
  let st = sp.beginInterval("Fetch", id: sp.makeSignpostID())
  defer { sp.endInterval("Fetch", st) }  // same StaticString name
  sp.emitEvent("CacheMiss")               // a point, not a span
  return try await api.feed()
}
\end{lstlisting}
\begin{lstlisting}[language=ShSheet]
log stream --level debug --predicate 'subsystem == "com.acme.app"'
xcrun xctrace record --template 'Time Profiler' --time-limit 30s \
  --output feed.trace --launch -- MyApp.app     # CI, no GUI
\end{lstlisting}

\section{Signposts — time, not words}
\begin{itemize}
  \item \textbf{Interval} = begin/end with the \emph{same static name}; the
        \ct{OSSignpostID} tells overlapping intervals apart. \textbf{Event} = one
        instant. Category \ct{.pointsOfInterest} lands in the \emph{Points of
        Interest} track next to Time Profiler samples.
  \item Near-free when nobody is recording. Xcode 27: the os\_signpost
        instrument shows \textbf{a track per signpost name} under its category.
  \item CI: \ct{XCTOSSignpostMetric(subsystem:category:name:)} in
        \ct{measure(metrics:)}; \ct{xctrace}: \ct{\dd{}run-name} (Xcode 26),
        \ct{\dd{}recording-options <json>} (27); \ct{xctrace export} takes
        \ct{.atrc}/\ct{.logarchive} directly and a time range (27).
\end{itemize}

\columnbreak

\section{Energy — what costs power}
{\footnotesize
\begin{tabular}{@{}>{\raggedright\arraybackslash}p{11mm}>{\raggedright\arraybackslash}p{32mm}>{\raggedright\arraybackslash}p{33mm}@{}}
\toprule
\textbf{what} & \textbf{drains it} & \textbf{fix}\\ \midrule
CPU & wake-ups, polling, timers, busy work & coalesce, timer tolerance, events\\
network & many small requests: the radio stays in high power after each & batch, prefetch, \ct{isDiscretionary}\\
location & best accuracy, continuous updates & coarsest that works, stop early\\
display & brightness, bright OLED pixels, idle 120 Hz animation & dark UI, stop idle animations\\
GPU & blur, offscreen passes, over-draw & cheaper effects, fewer layers\\
\bottomrule
\end{tabular}}

\section{Power Profiler (Xcode 26)}
\begin{itemize}
  \item Instrument on an iOS/iPadOS \textbf{device}: a \emph{system power} lane
        (with thermal + charging state) and your process's \textbf{power impact}
        per subsystem — CPU, GPU, display, networking. The score finds spikes;
        fix the highest-impact subsystem first.
  \item Two modes: tethered (Launch/Attach — needed for per-process metrics) or
        \textbf{passive} — start a trace in the device's Developer settings, use
        the app normally, open the \ct{.atrc} in Instruments (power + lower-rate
        CPU samples). The Energy Impact gauge in Xcode is the quick live view.
\end{itemize}

\section{Field data — MetricKit \& Organizer}
\begin{itemize}
  \item \textbf{MetricKit}: \ct{MXMetricManager.shared.add(subscriber)};
        \ct{MXMetricPayload} $\approx$ daily per device, \emph{…Metrics} for:
        cpu, gpu, display, locationActivity, networkTransfer, cellularCondition,
        applicationLaunch, applicationResponsiveness (hangs), animation
        (hitches), memory, diskIO, applicationExit, signpost. \emph{You} upload it.
  \item Your own field timings, aggregated into \ct{signpostMetrics}:
\begin{lstlisting}[language=SwiftSheet]
let h = MXMetricManager.makeLogHandle(category: "Feed")
mxSignpost(.begin, log: h, name: "Load")  // ... .end
\end{lstlisting}
  \item \textbf{Organizer}: Apple aggregates opt-in users; needs volume, compares
        versions. Battery Usage, Launch Time, Hang Rate (s of hang per hour),
        Memory, Disk Writes, Terminations. \textbf{Xcode 27}: \textbf{Hitches}
        replaces Scrolling (all animations); \textbf{Storage} (Documents \& Data,
        App Size); \textbf{Insights Overview} ranks regressions; \textbf{metric
        goals} (Battery, Disk Writes, Hang Rate, Hitches, Memory, Storage).
\end{itemize}

\section{Interview traps}
\begin{itemize}
  \trap{\ct{print}/\ct{NSLog} for diagnostics: eager strings, no levels, no
        redaction; \ct{print} never reaches a sysdiagnose.}
  \trap{Support asks for logs and there is nothing: \ct{debug}/\ct{info}
        weren't persisted — log what support needs at \ct{notice}+.}
  \trap{\ct{privacy: .public} on a token or email — that is a PII leak.}
  \trap{Energy measured in the Simulator, or plugged in and idle.}
  \trap{Organizer is not real-time: aggregated, opt-in, needs users.}
\end{itemize}

\section{Remember}
\textbf{Logger = words · signposts = time · Power Profiler = joules · MetricKit
/ Organizer = the field.}

\section{Likely questions}
\begin{enumerate}
  \item Which levels persist? — notice/error/fault; info if collected; never debug.
  \item Why \ct{Logger} over \ct{print}? — cheap, levelled, redacted, persisted.
  \item Time a flow for real users? — \ct{mxSignpost} $\to$ \ct{signpostMetrics}.
  \item Battery complaints? — Organizer + MetricKit, repro with Power Profiler.
\end{enumerate}

\end{multicols}

\noindent{\footnotesize\color{sheetGrey}\textit{Related:} instruments-performance
(Time Profiler, Hangs) · crashes-symbolication (\ct{MXDiagnosticPayload}) ·
lldb-deep · flags-experiments-observability (release gates) · background tasks}

\end{document}