| 1 | import AppKit |
| 2 | |
| 3 | // 🤖 ClickLab — the click-eating diagnostic rig behind the two dead-composer |
| 4 | // fixes (#930 focus-stealing, #1023 FrostedBand hitTest), made a permanent |
| 5 | // resident. The bug class is intermittent and not SwiftUI-debuggable (SwiftUI |
| 6 | // does not keep representable NSViews' z-order in step with its own stack, and |
| 7 | // NSView.hitTest walks NSView order), so a repro is only worth anything if the |
| 8 | // build that shows it can say who actually received the click. Debug builds |
| 9 | // carry the rig; plain Release builds compile it out. For an OPTIMIZED build |
| 10 | // that still records (a Debug daily driver multiplies every wedge at -Onone), |
| 11 | // build Release with SWIFT_ACTIVE_COMPILATION_CONDITIONS=CLICKLAB — and add |
| 12 | // CODE_SIGN_INJECT_BASE_ENTITLEMENTS=YES so tools/wedge-watcher.sh can still |
| 13 | // `sample` it mid-wedge. |
| 14 | // |
| 15 | // Log: <container>/Library/Logs/ClickLab.log (the app is sandboxed, so from |
| 16 | // the outside that's ~/Library/Containers/<bundle id>/Data/Library/Logs/). |
| 17 | // A launch rotates the previous session's log to ClickLab.prev.log. |
| 18 | // Opt out with `defaults write <bundle id> clickLab -bool NO`. |
| 19 | enum ClickLab { |
| 20 | #if DEBUG || CLICKLAB |
| 21 | private static var mouseMonitor: Any? |
| 22 | private static var pollTimer: Timer? |
| 23 | private static var observers: [NSObjectProtocol] = [] |
| 24 | private static var watchdog: DispatchSourceTimer? |
| 25 | private static var lastResponder = "" |
| 26 | private static var handle: FileHandle? |
| 27 | |
| 28 | private static let logURL: URL = { |
| 29 | let logs = FileManager.default.urls(for: .libraryDirectory, in: .userDomainMask)[0] |
| 30 | .appendingPathComponent("Logs", isDirectory: true) |
| 31 | try? FileManager.default.createDirectory(at: logs, withIntermediateDirectories: true) |
| 32 | return logs.appendingPathComponent("ClickLab.log") |
| 33 | }() |
| 34 | |
| 35 | // The heartbeat: rewritten from the MAIN thread every ~1s, so an outside |
| 36 | // watcher can `sample` the process while a wedge is still in progress |
| 37 | // (the in-log watchdog only reports a stall after it drains — too late |
| 38 | // to capture the blocked stack). |
| 39 | private static let beatURL = logURL.deletingLastPathComponent() |
| 40 | .appendingPathComponent("ClickLab.heartbeat") |
| 41 | private static var beatCounter = 0 |
| 42 | |
| 43 | private static let timeFmt: DateFormatter = { |
| 44 | let f = DateFormatter() |
| 45 | f.dateFormat = "HH:mm:ss.SSS" |
| 46 | return f |
| 47 | }() |
| 48 | |
| 49 | static func start() { |
| 50 | if UserDefaults.standard.object(forKey: "clickLab") != nil, |
| 51 | !UserDefaults.standard.bool(forKey: "clickLab") { return } |
| 52 | // Keep exactly one previous session — the interesting window is always |
| 53 | // "the run where it just happened", and unbounded append only grows. |
| 54 | let prev = logURL.deletingPathExtension().appendingPathExtension("prev.log") |
| 55 | try? FileManager.default.removeItem(at: prev) |
| 56 | try? FileManager.default.moveItem(at: logURL, to: prev) |
| 57 | |
| 58 | let info = Bundle.main.infoDictionary |
| 59 | let ver = "\(info?["CFBundleShortVersionString"] ?? "?") (\(info?["CFBundleVersion"] ?? "?"))" |
| 60 | log("=== ClickLab start — \(Bundle.main.bundleIdentifier ?? "?") \(ver)") |
| 61 | |
| 62 | mouseMonitor = NSEvent.addLocalMonitorForEvents(matching: .leftMouseDown) { event in |
| 63 | logMouseDown(event) |
| 64 | return event |
| 65 | } |
| 66 | // The caret ping-pong in #1023 played out over ~a second (click resigns |
| 67 | // to the window, the focus binding re-grabs a beat later) — a 0.25s |
| 68 | // change-only timeline is fine-grained enough to show that dance. |
| 69 | pollTimer = Timer.scheduledTimer(withTimeInterval: 0.25, repeats: true) { _ in |
| 70 | pollFirstResponder() |
| 71 | } |
| 72 | RunLoop.main.add(pollTimer!, forMode: .common) |
| 73 | |
| 74 | // The activation timeline — "dead right after loading into the |
| 75 | // window" implicates the focus gauntlet (app-activate → pullHome, |
| 76 | // window-key → the composer focus binding re-asserts), so stamp |
| 77 | // every transition the dead spell can be correlated against. |
| 78 | let nc = NotificationCenter.default |
| 79 | let acts: [(Notification.Name, String)] = [ |
| 80 | (NSApplication.didBecomeActiveNotification, "app ACTIVE"), |
| 81 | (NSApplication.didResignActiveNotification, "app inactive"), |
| 82 | (NSWindow.didBecomeKeyNotification, "window KEY"), |
| 83 | (NSWindow.didResignKeyNotification, "window unkey"), |
| 84 | ] |
| 85 | for (name, label) in acts { |
| 86 | observers.append(nc.addObserver(forName: name, object: nil, queue: .main) { note in |
| 87 | let w = (note.object as? NSWindow).map { " w#\($0.windowNumber)" } ?? "" |
| 88 | log("\(label)\(w)") |
| 89 | }) |
| 90 | } |
| 91 | |
| 92 | // The stall watchdog — distinguishes "clicks are being eaten" (main |
| 93 | // thread fine, hit-test chain wrong) from "the app is hung" (main |
| 94 | // thread blocked, nothing responds). A background ticker pings main |
| 95 | // every 200ms; any ping serviced >400ms late is a stall, and the |
| 96 | // printed lag ≈ how long main was wedged. |
| 97 | let ticker = DispatchSource.makeTimerSource(queue: DispatchQueue(label: "clicklab.watchdog")) |
| 98 | ticker.schedule(deadline: .now() + 1, repeating: .milliseconds(200)) |
| 99 | ticker.setEventHandler { |
| 100 | let sent = Date() |
| 101 | DispatchQueue.main.async { |
| 102 | let lag = -sent.timeIntervalSinceNow |
| 103 | if lag > 0.4 { log(String(format: "⏳ main-thread stall: ping serviced %.2fs late", lag)) } |
| 104 | } |
| 105 | } |
| 106 | ticker.resume() |
| 107 | watchdog = ticker |
| 108 | } |
| 109 | |
| 110 | private static func logMouseDown(_ event: NSEvent) { |
| 111 | guard let window = event.window, let root = window.contentView else { |
| 112 | log("mouseDown w#\(event.windowNumber) — no contentView") |
| 113 | return |
| 114 | } |
| 115 | // hitTest takes the point in the receiver's SUPERVIEW's coordinates |
| 116 | // (the theme frame, for a window's contentView). |
| 117 | let p = (root.superview ?? root).convert(event.locationInWindow, from: nil) |
| 118 | let hit = root.hitTest(p) |
| 119 | var chain: [String] = [] |
| 120 | var v: NSView? = hit |
| 121 | while let cur = v, chain.count < 10 { |
| 122 | chain.append(String(describing: type(of: cur))) |
| 123 | if cur === root { break } |
| 124 | v = cur.superview |
| 125 | } |
| 126 | let at = "(\(Int(event.locationInWindow.x)),\(Int(event.locationInWindow.y)))" |
| 127 | let notKey = window.isKeyWindow ? "" : " [window NOT key]" |
| 128 | if let hit { |
| 129 | let eater = hit is NSVisualEffectView ? " ⚠️ decorative view took the click" : "" |
| 130 | log("mouseDown \(at) w#\(window.windowNumber)\(notKey) → \(chain.joined(separator: " < "))\(eater)") |
| 131 | } else { |
| 132 | log("mouseDown \(at) w#\(window.windowNumber)\(notKey) → hitTest nil (falls to the window)") |
| 133 | } |
| 134 | composerAudit(in: root, click: event.locationInWindow, hit: hit) |
| 135 | } |
| 136 | |
| 137 | // Capture 1 (2026-07-17 10:14) showed clicks in the composer region |
| 138 | // reaching only NSHostingView — no composer took them, while programmatic |
| 139 | // focus still worked. With several spaces mounted, parked panes overlap |
| 140 | // the active one (their AppKit alpha/hidden are untouched by SwiftUI's |
| 141 | // opacity — only the .allowsHitTesting gate hides them from clicks), so |
| 142 | // "some OTHER composer's frame contains the click" is the NORMAL case. |
| 143 | // The one true anomaly: a click inside a composer frame that reaches NO |
| 144 | // composer at all — and then the blame walk names the ancestor whose |
| 145 | // hitTest kills it. |
| 146 | private static func composerAudit(in root: NSView, click: NSPoint, hit: NSView?) { |
| 147 | var composers: [ComposerTextView] = [] |
| 148 | func walk(_ v: NSView) { |
| 149 | if let c = v as? ComposerTextView { composers.append(c) } |
| 150 | for s in v.subviews { walk(s) } |
| 151 | } |
| 152 | walk(root) |
| 153 | if let taken = composers.first(where: { c in |
| 154 | guard let s = c.enclosingScrollView else { return false } |
| 155 | return hit?.isDescendant(of: s) ?? false |
| 156 | }) { |
| 157 | // Tag which instance took the click — a caret that lands in a |
| 158 | // tag the responder timeline never shows as the working composer |
| 159 | // is a ghost (a parked pane's field swallowing input). |
| 160 | log(" → composer #\(tag(taken))") |
| 161 | return |
| 162 | } |
| 163 | let containing = composers.filter { c in |
| 164 | guard let s = c.enclosingScrollView else { return false } |
| 165 | return s.convert(s.bounds, to: nil).contains(click) |
| 166 | } |
| 167 | for c in containing { |
| 168 | guard let scroll = c.enclosingScrollView else { continue } |
| 169 | let f = scroll.convert(scroll.bounds, to: nil) |
| 170 | log(String(format: "⚠️ click (%.0f,%.0f) inside composer #%@'s frame (%.0f,%.0f %.0f×%.0f) hit NO composer — blame walk:", |
| 171 | click.x, click.y, tag(c), f.origin.x, f.origin.y, f.width, f.height)) |
| 172 | blameWalk(from: scroll, click: click) |
| 173 | } |
| 174 | } |
| 175 | |
| 176 | private static func tag(_ v: AnyObject) -> String { |
| 177 | String(UInt(bitPattern: ObjectIdentifier(v).hashValue) & 0xFFFF, radix: 16) |
| 178 | } |
| 179 | |
| 180 | // Hit-test every ancestor of the field's scroll view directly at the |
| 181 | // click point: the first level that geometrically contains the point but |
| 182 | // hit-tests to nil (or outside itself) is the view gating the click — |
| 183 | // a stale SwiftUI allowsHitTesting on a PlatformViewHost, a mis-framed |
| 184 | // container, whatever it is, this prints its name. |
| 185 | private static func blameWalk(from scroll: NSView, click: NSPoint) { |
| 186 | var v: NSView? = scroll |
| 187 | while let cur = v, let sup = cur.superview { |
| 188 | let p = sup.convert(click, from: nil) |
| 189 | let ht = cur.hitTest(p) |
| 190 | log(String(format: " %@#%@ frameContains=%@ hitTest=%@ alpha=%.2f hidden=%@", |
| 191 | "\(type(of: cur))", tag(cur), |
| 192 | cur.frame.contains(p) ? "yes" : "NO", |
| 193 | ht.map { "\(type(of: $0))" } ?? "nil", |
| 194 | cur.alphaValue, cur.isHidden ? "YES" : "no")) |
| 195 | v = sup |
| 196 | } |
| 197 | } |
| 198 | |
| 199 | private static func pollFirstResponder() { |
| 200 | beatCounter += 1 |
| 201 | if beatCounter % 4 == 0 { try? Data("♥".utf8).write(to: beatURL) } |
| 202 | let window = NSApp.keyWindow |
| 203 | let fr = window?.firstResponder |
| 204 | let desc: String |
| 205 | if let fr { |
| 206 | let ptr = UInt(bitPattern: ObjectIdentifier(fr).hashValue) & 0xFFFF |
| 207 | desc = "\(type(of: fr))#\(String(ptr, radix: 16)) w#\(window?.windowNumber ?? -1)" |
| 208 | } else { |
| 209 | desc = window == nil ? "no key window" : "nil" |
| 210 | } |
| 211 | guard desc != lastResponder else { return } |
| 212 | log("responder: \(lastResponder.isEmpty ? "—" : lastResponder) → \(desc)") |
| 213 | lastResponder = desc |
| 214 | } |
| 215 | |
| 216 | private static func log(_ line: String) { |
| 217 | NSLog("[ClickLab] %@", line) |
| 218 | let data = Data("\(timeFmt.string(from: Date())) \(line)\n".utf8) |
| 219 | if handle == nil { |
| 220 | if !FileManager.default.fileExists(atPath: logURL.path) { |
| 221 | FileManager.default.createFile(atPath: logURL.path, contents: nil) |
| 222 | } |
| 223 | handle = try? FileHandle(forWritingTo: logURL) |
| 224 | _ = try? handle?.seekToEnd() |
| 225 | } |
| 226 | try? handle?.write(contentsOf: data) |
| 227 | } |
| 228 | #else |
| 229 | static func start() {} |
| 230 | #endif |
| 231 | } |
| 232 | |
amadan