diag(ios,audio): log AVAudioSession state + route changes around picker overrides

Add structured NSLog instrumentation to AppDelegate.swift and debugPrint
chains in voice_compact.dart::_AudioOutputPickerSheetState so we can
correlate user picker taps with what iOS actually does to the route.

Three diagnostic streams:

* 'chanora.session[<tag>]' from Swift — full session snapshot (category,
  mode, sampleRate, ioBufferDuration, current route inputs+outputs,
  preferredInput) emitted on every setActive and every
  AVAudioSession.routeChangeNotification with the reason decoded
  (override / routeConfigurationChange / newDeviceAvailable / etc).
* 'chanora.route[<tag>]' from Dart — current route's inputs+outputs
  emitted before/after every overrideOutputAudioPort or
  setPreferredInput call, plus a delayed re-check at +250 ms to detect
  silent reverts.
* Existing 'chanora: ...' debugPrint lines from the picker now include
  the OK case (override returned, setPreferredInput returned) so we see
  a positive signal in the log when the API didn't throw.

Used to root-cause the 'speaker selector not working' issue: the
hypothesis is that cpal's RemoteIO AudioUnit reacts to its own format
configuration notifications by triggering routeConfigurationChange
that reverts our Dart-side override. The logs will confirm or deny
this — if we see 'chanora.session[routeChange.override] out=Speaker'
followed by 'chanora.session[routeChange.routeConfigurationChange]
out=Receiver' within a few hundred ms, that's the smoking gun.

Pure diagnostic commit. No behavioural change. Logs are NSLog +
debugPrint so they appear in Xcode console / 'flutter logs' / the
device log via Console.app or 'devicectl device log'.
This commit is contained in:
EdisonJwa
2026-05-16 23:57:50 +08:00
parent b1d117033e
commit da631a2bef
2 changed files with 113 additions and 28 deletions
@@ -85,6 +85,20 @@ import AVFoundation
object: nil
)
// Diagnostic: subscribe to every AVAudioSession route change so
// we can correlate user picker actions with what iOS actually
// does to the route. The reason printed here ("override",
// "newDeviceAvailable", "categoryChange", etc.) tells us
// whether our Dart-side override was honoured or silently
// reverted by another component (e.g. cpal's RemoteIO unit
// reacting to its own configuration change).
NotificationCenter.default.addObserver(
self,
selector: #selector(handleRouteChange(_:)),
name: AVAudioSession.routeChangeNotification,
object: nil
)
// Request microphone access on first launch rather than waiting
// for the user's first voice-channel join. The latter is
// surprising: the user has only tapped "connect to server" and
@@ -123,11 +137,69 @@ import AVFoundation
do {
try AVAudioSession.sharedInstance().setActive(true, options: [])
NSLog("chanora_flutter: AVAudioSession activated on foreground")
logSessionState(tag: "didBecomeActive")
} catch {
NSLog("chanora_flutter: AVAudioSession setActive failed: \(error)")
}
}
/// Log the full AVAudioSession state with a diagnostic tag. Used
/// after every state transition (setActive, route change) so we
/// can correlate user-perceived audio bugs with what iOS thinks
/// the session looks like. Output is parseable by grep
/// `chanora.session\[`.
private func logSessionState(tag: String) {
let s = AVAudioSession.sharedInstance()
let route = s.currentRoute
let outs = route.outputs.map { "\($0.portType.rawValue)/\($0.portName)" }.joined(separator: ",")
let ins = route.inputs.map { "\($0.portType.rawValue)/\($0.portName)" }.joined(separator: ",")
let preferredInput = s.preferredInput?.portName ?? "<nil>"
NSLog("""
chanora.session[\(tag)] \
cat=\(s.category.rawValue) \
mode=\(s.mode.rawValue) \
sr=\(s.sampleRate) \
ioBuf=\(String(format: "%.4f", s.ioBufferDuration)) \
out=[\(outs)] in=[\(ins)] \
preferredInput=\(preferredInput)
""")
}
/// Called by `routeChangeNotification`. iOS posts this whenever
/// the route is reconfigured for any reason user toggles
/// Bluetooth, plugs in headphones, our `overrideOutputAudioPort`
/// call, OR (the suspected bug here) when cpal's RemoteIO
/// AudioUnit reacts to its own format change and resets the
/// route. The `reason` field tells us which case it is:
///
/// * `.override` : our Dart-side override took effect.
/// * `.routeConfigurationChange` : something else (cpal?)
/// triggered an internal reconfig.
/// * `.newDeviceAvailable` / `.oldDeviceUnavailable` :
/// user hardware change.
/// * `.categoryChange` : someone (us or another app) set a
/// new category.
@objc private func handleRouteChange(_ note: Notification) {
guard let reasonValue = note.userInfo?[AVAudioSessionRouteChangeReasonKey] as? UInt,
let reason = AVAudioSession.RouteChangeReason(rawValue: reasonValue) else {
NSLog("chanora.routeChange[unknown-reason]")
return
}
let reasonName: String
switch reason {
case .unknown: reasonName = "unknown"
case .newDeviceAvailable: reasonName = "newDeviceAvailable"
case .oldDeviceUnavailable: reasonName = "oldDeviceUnavailable"
case .categoryChange: reasonName = "categoryChange"
case .override: reasonName = "override"
case .wakeFromSleep: reasonName = "wakeFromSleep"
case .noSuitableRouteForCategory: reasonName = "noSuitableRouteForCategory"
case .routeConfigurationChange: reasonName = "routeConfigurationChange"
@unknown default: reasonName = "default(\(reasonValue))"
}
logSessionState(tag: "routeChange.\(reasonName)")
}
func didInitializeImplicitFlutterEngine(_ engineBridge: FlutterImplicitEngineBridge) {
GeneratedPluginRegistrant.register(with: engineBridge.pluginRegistry)
}