Skip to content

CONNECTION.md

Latest commit

 

History

History
740 lines (615 loc) · 50.7 KB

CONNECTION.md

File metadata and controls

740 lines (615 loc) · 50.7 KB
Raw

CONNECTION.md

How the app talks to a receiver: the two transports, the reconnect loop that keeps the telnet socket alive, who decides when to hang up, and what Android's background restrictions do to all of it.

Read this before touching core/ResilentConnector, core/Connector, ActiveHandler or http/HTTPSupport. Most of what looks removable in there is load-bearing, and the reasons are field observations rather than theory. Open work is in TODO.md; this file describes what the code does today.

Two independent transports

Ports 23 and 80 are the defaults; ConnectionConfiguration also parses IP[:controlport[:httpport[:httpip]]]. That matters beyond the port number — with such an extended config checkAddress() returns true without probing anything, so the reachability story below does not apply to those users at all.

  1. Telnet, port 23 — the real control channel. core/Connector holds a raw socket, writes commands terminated with \r, and parses incoming lines into InData. Two daemon threads per connection, receiver and sender; the sender paces commands by SEND_DELAY (100 ms) because the receivers drop them otherwise.
  2. HTTP, port 80 — http/AVRHTTPClient scrapes the receiver's own web UI (*.asp, XML endpoints) for things the telnet protocol does not expose: input/zone names, quick-select presets, NET audio search. http/Series08* parse the 2008-series variant. Every request goes through http/HTTPSupport (HttpURLConnection, GET and form POST, nothing else); its three callers are http/AVRHTTPClient, http/Series08Reader and — easy to miss — core/display/NetDisplay.

Three things in HTTPSupport are deliberate and load-bearing against the receivers' 2008-era GoAhead webservers, and all three look removable to someone who does not know why they exist:

  • Accept-Encoding: identity — the old Apache client never asked for gzip, Android does.
  • setFixedLengthStreamingMode — so the request body is never sent chunked.
  • CookieHandler.setDefault(new CookieManager()) in AVRApplication.onCreate. The receivers tested so far send no Set-Cookie at all, so this looks pointless — but Series08Reader fetches r_option1.asp purely to establish state that the following d_option1.asp reads back, and the Apache client it replaced carried a cookie store. Without a handler HttpURLConnection shares nothing between requests, and the failure would be silent (empty quick-select names). readSeries08Info() clears the store per run, because the old store was per-client and did not outlive one read.

Receivers speak plain HTTP, so android:usesCleartextTraffic="true" in the manifest is load-bearing too — removing it kills the whole scraping path.

The reconnect loop

ResilentConnector runs a long-lived loop on a plain daemon thread owned by AVRApplication — not a Service. Killing or backgrounding the app kills the connection. That is a 2010 design decision and still open in TODO.md.

One pass of Reconnector.run(): probe reachability (checkAddress()), open a Connector, publish it, then block in waitUntilClosed() until the socket drops; probe again, clear the state, wait, repeat. The wait comes from RECONNECT_DELAY and runs 2, 4, 8, 16 s — the array's leading 1 is never used, because the index is incremented before the sleep. It only resets after a successful connection, so sitting in the foreground through a bad patch can leave you waiting 16 s after the network is fine again. A resume escapes it: forceReconnect() builds a fresh Reconnector whose index starts at 0.

Why nothing waits for the old thread

stopConnector() interrupts the reconnect thread and returns immediately. It does not join it, because the thread is typically inside ConnectionConfiguration.checkAddress() → InetAddress.isReachable() plus a few testPort() connects, and none of those react to interrupt(). Waiting ran into its full timeout and then continued with the thread still alive — a second of blocked UI thread, since stopConnector() is reached from ActiveHandler on the main thread. core/ThreadHandlerTest pins that it returns promptly.

So a superseded thread keeps running for a few seconds, and several of them can be alive at once. Their log lines are distinguishable: the thread is named ResilentThreadHandler-<n>, where <n> is the generation. Everything that keeps them harmless rests on one mechanism:

The generation counter

ResilentConnector.generation is an AtomicInteger. startConnector() bumps it and hands the new value to the Reconnector as its epoch; stopConnector() bumps it before tearing anything down, so a superseded thread sees isCurrent() == false and must not touch shared state any more. Every write in run() is guarded by it.

Two of those guards need more than a check:

  • publishConnector(epoch, c) is synchronized and re-checks the epoch under the monitor, against closeAndClearConnector(). A plain if (isCurrent()) connector = c; would only narrow the window: if the bump lands between check and assignment, a superseded thread drops a live Connector into the field after the cleanup already ran. Nobody closes that socket, the receiver keeps a second telnet session open, and isRunning() reports the dead connection as current — the same shape as the failure in What Doze does below, reached by a different route. That one was observed; this one was reasoned about in PR #26 and guarded before it could happen.
  • The block after the second checkAddress() is guarded because that call blocks about a second in ping and port timeouts. The guard narrows the window; what actually closes it is publishConnector() underneath.

When a connection goes quiet

Socket.isConnected() stays true forever once a connect succeeded, including for a socket that Doze or a network change severed minutes ago. Nothing else notices either: receivers send nothing on their own, so no traffic is not evidence of anything. The reading loop therefore watches the silence itself.

The read watchdog. The socket carries setSoTimeout(READ_TIMEOUT) (5 s), which is a tick rate and not a deadline — a quiet connection is normal. After IDLE_PROBE (60 s) without a single byte the receiver thread sends one PW? itself; if PROBE_GRACE (10 s) passes with no answer it closes the connection and the reconnect loop builds a new one. PW? because every model answers it in every state — a receiver in standby replies PWSTANDBY, which is where StatusFlag.Power comes from in the first place.

Silence is counted in timeout ticks rather than by the clock, because the question is "were we awake and heard nothing": a frozen thread stops counting, where the clock would run on.

What it costs is one probe per minute, forever. Nothing else sends on the control channel while the user is idle, so the watchdog never finds the line busy: measured on an AVR-3310, four probes in four minutes, each answered within 22–118 ms. A resting connection used to rest; now it ticks.

Doze is less of a worry than it looks, and for a reason outside this file: with the screen off ActiveHandler hangs up 10 s after the activity pauses (Who decides when to hang up), so there is no connection left for the watchdog to take down. Measured 2026-09-25 on a Pixel 8 in forced deep idle:

19:50:04.415  ActiveHandler.activity paused AVRRemote
19:50:04.415  auto disconnect :10sec
19:50:09.438  read failed ... Software caused connection abort
                at Connector$Receiver.readChar(Connector.java:76)
19:50:09.446  Reconnector:connection to [192.168.10.30] closed
19:50:14.418  run stopConnectorRunnable

The abort came from the suspended network, not from the watchdog — it arrives through readChar() like any other IOException and is passed on. What remains untested is a foreground connection held across a real Doze window; there the ticks would accumulate while the network is down.

Two rules in the reading loop are load-bearing:

  • A timeout in the middle of a line gives up like any other. The half-read message is lost, and that is right: the connection is being abandoned. Keeping it would mean switching the watchdog off for the rest of the line, and a connection that dies one byte into a message would hang for good. Every byte read resets the idle count, so a slow-but-alive sender is never mistaken for a dead one.
  • The teardown calls Connector.close(), not socket.close(), because only that also interrupts the sender — otherwise it stays parked in sendQueue.take() and outlives the connection it served. That leak predates the watchdog; the watchdog just reaches the path often enough for it to matter.

core/ConnectorTest covers both on the JVM against a fake receiver on a local ServerSocket, with the three timings injected through a package-private constructor so the suite spends milliseconds where the app spends minutes.

What the receiver does when its one session is taken

Worth knowing before building anything here, because it was assumed the other way round for a while. The receiver allows exactly one telnet session, and Android kills the app's process on a package update the same way it does on a force-stop — no onDestroy, no finally. The kernel sends the FIN instead, unless the Wi-Fi is asleep or gone at that moment, and then the receiver holds a session that no longer exists.

Measured on an AVR-3310 on 2026-09-25, in four arrangements — session held by another device, session held by the app's own superseded connect, Wi-Fi lost and restored with the process alive, and the real thing (Wi-Fi off, force-stop, Wi-Fi on, restart):

It refuses. ECONNREFUSED on port 23, every time, while ping and port 80 keep answering. It never once accepted the socket and then stayed silent. That is why there is no handshake in the connect path: the case it would catch has not been observed on this model, and what the user actually gets is the busy-port dialog (Reachable says nothing about port 23), which fired correctly in exactly this situation. Whether another model behaves differently is unknown — there is one receiver to test against and 60 model classes.

It does let go eventually. The same session was still refused 13 minutes after the ghost was created and was accepted again 28 minutes after it, so this receiver times its dead sessions out somewhere in between — the window is that wide because nothing was watching in between. Worth knowing when reading the busy dialog's advice: pulling the mains plug is the reliable fix, not the only one, and a user who waits half an hour may report the problem as having "fixed itself".

Who decides when to hang up

ActiveHandler is the only owner of the disconnect policy. AVRApplication.activityResumed() and activityPaused() feed it; every activity reports through them.

  • contextPaused() schedules a StopConnectorTask on the StopConnector-Timer after the user's disconnect time (AVRSettings.getDisconnectTimeout, default 10 s, selectable up to 7200 s). Nothing is torn down immediately — the screen going off just pauses the activity.

  • contextResumed() picks one of three paths, on a quick return — back within the shorter of the disconnect time and MAX_QUICK_RETURN_SEC (60 s), so 10 s at the default:

    • quick return and isRunning() → leave the connection alone,
    • quick return but not running → reconfigure(), which itself short-circuits if the config is unchanged and a loop is already running,
    • otherwise → forceReconnect(), unconditionally.

    distrustConnection() voids the quick return for the next resume. AVRApplication calls it when the Wi-Fi changed while no activity was active — lost, back, or switched — and when a receiver reset finished in the background, because in each case the socket isRunning() would vouch for may hang on a network that is gone.

The 60 s are a cap, not the window, and the reason for the cap is that the disconnect time may be set as high as two hours while isRunning() is only worth seconds: it rests on Socket.isConnected(), which stays true forever once a connect succeeded, including for a socket Doze severed long ago. The shortcut is for rotation, dialogs and tab switches. The read watchdog does take such a socket down now, but only some 70 s after it went quiet and only while the receiver thread is really running — which in the background is exactly what is not guaranteed. So the cap stays.

In practice Android hangs up first. Measured on a Pixel 8 with Android 17 against an AVR-3310 on 2026-10-10, disconnect time 5 min, screen on and on the charger, so no Doze involved:

15:42:21.048  ActiveHandler.activity paused AVRRemote
15:42:27.079  (netpolicy) Firewall rule changed: 10583-background-default
15:42:27.096  read failed ... Software caused connection abort

dumpsys netpolicy shows the app's UID as blocked=APP_BACKGROUND while it is not in the foreground: about six seconds after onPause the system cuts its network and aborts the socket. So no disconnect time above that keeps a connection alive, and a "never" option could not either — only a foreground service would. What the setting still decides is how long the quick-return shortcut may trust a socket, and by the time that matters the socket is usually gone. The reconnect on return took 1.06 s in the same run; the abort apparently reached the receiver, the port was free at once.

What the cut used to cost: the reconnect loop did not know about the foreground, so it kept retrying against the block until StopConnectorTask fired — up to two hours of 16 s rounds that cannot succeed. Reconnector.waitBeforeRetry() now ends the loop instead, before and after its backoff pause, logged as in background -> no further attempt. Three details carry it:

  • "Background" is ActiveHandler.isActive() or a visible process (ActivityManager.getMyMemoryState, importance up to IMPORTANCE_VISIBLE), wired in AVRApplication through ResilentConnector.setForeground. isActive() alone is also false behind a system dialog, a chooser or in an unfocused split-screen pane, where the process keeps its network — the block follows the process state, not onPause.
  • The loop retires itself under the ThreadHandler monitor (retire()), the one isDefined() takes. Decided and cleared separately, there would be a window in which the thread has decided to go but isAlive() still says yes; a quick-return reconfigure() in that window would see a running loop, start none, and leave none behind. Under the monitor either the thread goes first and isDefined() is false afterwards, or reconfigure() goes first — and then contextResumed() has already set the activity active, so the thread stays. ThreadHandlerTest pins this, and that a detached thread does not retire its successor.
  • Only rounds that already failed are cut short. The first round after a start or a reconnect still runs, which matters for the grant path, where triggerReconnect() comes before the activity is resumed again.

Where Android does not cut background networking, this costs a background drop its retry; the next resume reconnects as it would after any pause longer than the quick-return window.

StopConnectorTask also checks whether an activity became active again before it fires, and reconnects itself if a resume slipped in between its check and the stop. Both belong to the Doze story below.

What Doze does

This is where the interesting failures come from. All of the following is observed, not theory.

The process is frozen and broadcasts are delivered late. This caused the one field report we have a log for (2026-08-03). SCREEN_OFF was queued at 18:27 while the app was in the background and arrived at 18:48:07.513 — 49 ms after the user brought the app back and forceReconnect() had started a new reconnect thread. The old ACTION_SCREEN_OFF receiver called connector.stop() unconditionally and invalidated exactly that thread. There is no way back from there: no further contextResumed() comes, because the activity is already resumed. The app looked dead until it was killed and restarted. The receiver is gone; ActiveHandler alone decides now.

Timers catch up. java.util.Timer fires tasks it missed while the process was frozen, so a StopConnectorTask deferred by Doze can go off right after a resume and stop a connection that was just built. cancelCurrentTask() in contextResumed() only wins that race sometimes, hence the guard in the task, and the self-heal after it because check-then-act is not atomic.

Wi-Fi power save makes a reachable receiver look unreachable. Measured 2026-08-04 on a Pixel 8 against an AVR-3310 on 2.4 GHz, all three within a minute of each other:

ping to the receiver port 23
Mac on the same LAN 8 ms connects
phone, awake for a while 46–62 ms connects
phone, just woken fails entirely 2500 ms connect timeout

The Mac is the control here: it kept answering throughout, so the receiver was demonstrably up the whole time.

The radio sleeps between beacons and only wakes on DTIM. AVRTargetTester.PING_TIMEOUT is 250 ms for the pre-connect probe and twice that for the one after a close (cfgTest doubles it), so right after the user picks the phone up, checkAddress() reports "not reachable" for a receiver that is plainly there. The connect is attempted regardless — the "Auf jeden Fall versuchen" comment in Reconnector.run() covers that — so this is about displayed state and the backoff, not about refusing to connect. Still open, see TODO.md.

Repeated on 2026-10-11 with the same phone and receiver, and not reproduced. On USB the phone charges and Wi-Fi power save stays off: three rounds of three minutes with the screen off, and every ping arrived — 23–126 ms for the first one with the screen still off, 5–98 ms right after waking. On battery, one run survived in logcat (the other rolled out of the buffer): locked for a few minutes, unlocked, app opened, ping 33 ms and connected 1.2 s after onResume. So the August failure is real but not the common case, and nothing measured since justifies a longer timeout. Since then testAddress() logs the duration of every ping (ping /… 33 ms, ping failed /… after 251 ms), so a report from an affected device carries the number. Two things for whoever repeats this: measure on battery, and raise the logcat buffer first (adb logcat -G 16M), or the interesting run is gone by the time the phone is plugged back in.

The process can also simply be reclaimed, and then the daemon thread dies with it. That is the Service item in TODO.md. Worth stressing: the field report above was not this. The process had survived — openend at appears only at the app's own restart.

How connection state reaches the UI

EnableManager drives view enablement from a small set of StatusFlags, in this order: Logging, WLAN, Reachable, Connected, Power, Zone1–Zone4. This is why most buttons are greyed out until a receiver is actually connected — worth knowing when testing without hardware.

The flags are not independent. setStatus() cascades through a deliberate switch fallthrough: clearing Reachable also clears Connected, Power and all four zones. One missed ping response greys out nearly the whole UI — which is what makes the PING_TIMEOUT observation above more than cosmetic. Setting cascades the other way: Power implies Connected implies Reachable.

Zone4 was missing from that reset until August 2026, so on a four-zone receiver — AVR5308, AVR4308, AVR4810, AVR5805 — those controls stayed enabled after the connection dropped while zones 1–3 greyed out. Worth knowing when reading an older log.

Reachable says nothing about port 23

AVRTargetTester.testAddress() pings, tests port 80, and for the scan also 5000/6666 (or 8080 + 111 on 2016-and-later models). The control port is never probed. So the app can report a receiver as reachable while the one port it needs is refusing — and the Connectivity Problem dialog then says "the receiver is not responding", which is simply untrue.

That case has its own text since September 2026. Reconnector sets controlPortBusy when a connect fails while ping and port 80 answer, and ConfigurationAssistant picks AVRControlPortBusy over AVRReset accordingly: the receiver is there and the control session it allows is most likely taken — by another app, another device, or one that was never closed — and only cutting mains power reliably frees it. Standby usually does not, because the network stays awake; that is why the dialog's "Automatic" button, which sends an HTTP standby/on cycle, often leaves the user exactly where they were (issue #11). The text hedges on purpose: what the app knows is that port 80 answered and port 23 did not, which the receiver's own IP-control setting can produce just as well.

The flag is deliberately a message selector and nothing more — it feeds no StatusFlag and changes no connect behaviour. It also decides whether the dialog appears at all: checkStatus() routes to checkReset() on Reachable or controlPortBusy, because Reachable additionally demands the UPnP ports, and without that a model offering neither 5000/6666 nor 8080 + 111 would get the "configure your IP" dialog for an address we had just been talking to.

Three details keep it from lying:

  • It says nothing for an extended config. checkAddress() returns true there without probing (see the top of this file), so reachable is not a finding and the flag stays false — checkControlPortBusy() asks ConnectionConfiguration.isProbing() first. Without that, every failure for those users, unplugged receiver included, would claim the box had answered.
  • It is computed before Reachable is published, not after. setStatus(Reachable, false) makes Connected defined by fallthrough, and that is the condition on which ConnectionProgressMonitor opens the dialog that reads the flag. The probe in between blocks about a second, so the other order leaves the previous run's value readable for that second. Being a second late with Reachable on a failed attempt costs nothing; the second isCurrent() after the probe is the same guard as at the loop's other blocking checkAddress().
  • clearState() clears it. Otherwise the finding survives an IP change or a stop(), and the next dialog recommends the mains plug for an address we never spoke to. The failure path in Reconnector.run() does not call clearState(), so the flag still outlives the run that sets it.

Why a dialog and not a log line: debugMode defaults to adb, so there is no file log on a normal installation and no way to ask for one after the fact. Whatever the app does not say on screen is lost.

Reading a log

log/SDLogger writes it, log/FeedbackReporter mails it. One line looks like this, and a message can run over several lines — anything not matching the header is a continuation:

2026-08-04  20:22:07.667 #0 - INFO : [main] openend at Tue Aug 04 20:22:07 GMT+02:00 2026

Sort by #seq, never by timestamp or line order. Neither of those is the order the events happened in: java.util.logging stamps the time when the LogRecord is built but writes later, so threads overtake each other — the field log from 2026-08-03 has 7 inversions in its 2488 header lines, one of them right where it mattered. (Count header lines only. A naive line-wise check counts the 184 continuation lines too and reports 99, which is wrong.) Sorting by the timestamp does not repair it either, because it only has millisecond resolution and 65 % of those lines share a millisecond with another. #seq comes from LogRecord, assigned in the constructor from the same instant as the time, and it is the one total order within one process run — on two runs from a Pixel 8 it removed every inversion (9 and 4 respectively, 0 after sorting).

#seq restarts at #0 in each process, and one log file usually holds several runs appended, so split on the openend at lines before sorting. Sorting a whole file by #seq interleaves the runs and produces garbage: on that same file it turned 13 inversions into 259. The counter can also have gaps — it is JVM-global and a rotation boundary cuts the file mid-stream — though in practice nothing else in the process uses java.util.logging, and one of those runs was gapless from #0 to #689.

An exception is followed by its type, message and up to MAX_TRACE frames of stack, indented with tabs, Caused by: per cause. Before 1.6.1 the formatter dropped the Throwable entirely, so older logs carry only the message — reading macros.txt failed there could be the harmless FileNotFoundException it usually is, or anything else.

ReceiverStatus.toString() walks StatusFlag.values() rather than its own map, so the flags always appear in the same order and two status lines can be diffed as text. Over the map they could not: 3 of the 11 flag sets in that field log show up in more than one order, two of them in three.

What the thread names tell you

The name is captured in SDLogger.withThread() at log time rather than in the formatter, so it stays right no matter which thread does the writing. logcat has no such field — it carries its own tid column. For connection questions this is where most of the signal is:

thread what it is
main lifecycle, forceReconnect, everything from an activity
ResilentThreadHandler-<n> a reconnect loop, <n> is its generation; several can be alive
receiver / sender the two socket threads of one Connector
StopConnector-Timer the auto-disconnect timer
StateCheckThread the re-query after a connection came up (core/AVRState)
LoadXMLStatus the HTTP scraping from StatusAreaManager

A healthy start looks like this — one generation, and data arriving:

#79  [main]                      Reconnector:start new connector 192.168.10.30
#81  [ResilentThreadHandler-2]   Reconnector:build new connection to [192.168.10.30]
#83  [ResilentThreadHandler-2]   Reconnector:reachable 192.168.10.30 : true
#145 [ResilentThreadHandler-2]   Reconnector:connection to [192.168.10.30] established
#156 [receiver]                  RECEIVED [PWSTANDBY(...)]

A normal teardown and re-establish — the auto-disconnect timer drops the connection while the app is in the background, the user comes back 13 s later, a new generation takes over. Note that the two sides run on different threads, which is how you tell them apart:

#439 [StopConnector-Timer]       Reconnector:connector detached (ResilentThreadHandler-2)
#440 [ResilentThreadHandler-2]   Reconnector:connector interrupted -> return
#465 [main]                      Reconnector:start new connector 192.168.10.30
#467 [ResilentThreadHandler-5]   Reconnector:build new connection to [192.168.10.30]

What a dead loop looked like before the fix — a teardown with no start new connector after it, and then nothing at all until the app was restarted:

activity resumed AVRRemote
Connector forceReconnect ip: [192.168.10.30]
Reconnector:start new connector 192.168.10.30
System StandBy ...                            <- broadcast from 20 minutes earlier
stop connector
Reconnector:connector stopped

So: a teardown line that is not followed by a new generation starting is the smell.

What the network and permission lines tell you

First, what arrives at all. The log mode defaults to adb, so there is no log file. What a feedback mail carries instead is the report header and — unless the user unticks Include recent log lines — the in-memory ring buffer at the end of the text (Logger.RING_SIZE lines, oldest first; crash reports carry it too). Its lines look like the file's, minus the #seq and with other level names — DEBUG/INFO/ERROR here, FINE/WARNING there:

2026-09-27  09:06:07.449 - ERROR : [ResilentThreadHandler-4] Reconnector:IOException [192.168.10.30] -> java.net.ConnectException: … ECONNREFUSED (Connection refused)

An error keeps its exception's type and message but no stack trace. The order is the order the entries reached the buffer, under one lock, which is good enough without a #seq. It covers minutes at most while a connection is up — every state query is dozens of SEND/RECEIVED lines — so for anything older, and for the header's snapshot of the network, the header still has to answer on its own. These lines are there for that:

header line what it settles
IPv4 every interface with its prefix — Ethernet or tethering show up here and nowhere else
WiFi whether a Wi-Fi is tracked, and its address and prefix
LocalNet BLOCKED / granted plus the asked marker, or not enforced (SDK …, target …); when blocked also denied:for good (only the app settings help), will ask again or unknown
Binding how the last socket to the Wi-Fi was set up — accepted, refused with EPERM, skipped and why, or none yet
CtrlPort busy if the last failed attempt found port 23 taken — decides the assistant's text

LocalNet: BLOCKED explains a log in which every connect times out and reachable stays false: under Local Network Protection that looks exactly like a receiver that is switched off.

In a full log, these lines carry the same questions over time:

line meaning
LocalNetwork: WiFi available / lost / address arrived the callback; lost only for a Wi-Fi that was there
LocalNetwork: WiFi lost, falling back to another the bound Wi-Fi went away while a second one was still up; the binding moves to the most recently available of those
LocalNetwork: WiFi lost, another stays bound a Wi-Fi the binding had already moved away from went away — make-before-break; a connection opened before the move still ran over it
Wifi switched, active:… either of the two lines above reached AVRApplication; with active:true it reconnects at once instead of waiting for the old socket to fail, with active:false the next resume reconnects even inside the quick-return window
LocalNetwork: WiFi not present at startup the seed — no Wi-Fi was ever reported, nothing dropped
LocalNetwork: WiFi address changed from … new IPv4 address or prefix on the same Wi-Fi, e.g. roaming
binding accepted / binding refused with EPERM (VPN?) how sockets leave; logged on every change, the first one included
binding skipped: … outside the WiFi subnet the target was judged and is not in the Wi-Fi's prefix
binding skipped: the WiFi has no IPv4 address yet / … unresolvable or not IPv4 not judged at all — says nothing about where the receiver is
local network permission: granted / requesting / denied for good -> not asking what the app did about the permission, once per start and per scan
local network permission result: granted / denied, Android will ask again / denied for good - … the answer to the request. From a fresh state the first denial asks again and the second is for good; the back key on the dialog counts as a denial. "For good" may come from Android itself, without a dialog
local network permission request was interrupted the dialog went away unanswered; the app asks again next time
assistant: opening app settings / menu: opening app settings the user went to the app info page — from the blocked-network hint's button, or from the main menu
Reconnector:connect failed, reachable:… controlPortBusy:… the verdict after a failed attempt
assistant: reset dialog, control port busy:… / assistant: local network blocked dialog which hint the user actually saw
testAddress failed <address> a probe — scan candidate or the reconnect loop's checkAddress — could not even try a port: usually a binding refused with an errno other than EPERM, or the ping itself threw

In the file log, no binding … line at all means no socket to the Wi-Fi was ever set up: either no Wi-Fi was tracked, or nothing has connected yet. In the ring buffer that conclusion does not hold — the one line is gone after a few minutes of connection — so read the Binding header line there instead, which comes from the state and not from the log.

One network callback, and every socket bound to it

scan/LocalNetwork is the only place that knows anything about the local network. It registers one ConnectivityManager.NetworkCallback in AVRApplication.onCreate and from it answers four questions: is a Wi-Fi up, which Network object is it, what IPv4 address does the device hold in it, and — when the answer is no — why not.

Two details there are answers to real failures, not taste:

  • The request carries no NET_CAPABILITY_INTERNET. NetworkRequest.Builder defaults to NOT_RESTRICTED/TRUSTED/NOT_VPN only, and registerNetworkCallback reports every matching network rather than just the default one. That is what keeps a Wi-Fi without internet — dead WAN, captive portal, a deliberately isolated AV network — counted as connected while mobile data is active. The receiver is plainly there in that case; the app used to refuse the whole scan on it. clearCapabilities() would be the explicit way to say this and is API 30, above minSdk 24.
  • The listener runs on the main thread, by Handler.post() from inside the callback. The BroadcastReceiver this replaced ran in onReceive on the main thread, so the Wi-Fi changes reach EnableManager in the order they happened, as before. (setStatus() is synchronized now, log line included so the setEnabled lines follow #seq in the order of the changes; it used to be a bare read-modify-write, and the main thread was the only protection this path had.) The Handler overload of registerNetworkCallback would be the direct way to say it, and is API 26.
  • The old receiver's one crash was closed by removal, not by understanding. 1.5.1 crashed with an NPE in AVRApplication$1.onReceive on a Pixel 8 Pro with the Android 17 Beta: getNetworkInfo(TYPE_WIFI) returned null. The receiver and its WifiManager broadcast are gone, and with them the crash site; the null was never reproduced on a Pixel 8 with the finished Android 17 (three Wi-Fi off/on cycles, airplane mode, Data Saver on a metered Wi-Fi in the background). Worth remembering if a null of the same kind turns up in LocalNetwork.

Everything that opens a socket to the receiver goes through LocalNetwork — core/Connector (telnet 23), http/HTTPSupport (both entry points, via Network.openConnection), scan/AVRTargetTester and the SSDP socket. Without the binding, connect() takes the default network, which beside active mobile data is not the Wi-Fi, and the receiver is unreachable in exactly the case the paragraph above works so hard to recognise. bindSocket per socket, never bindProcessToNetwork() — the latter applies to the whole process, including connections that have no business on the local network.

A unicast socket is bound only when its target lies in the Wi-Fi's own subnet. The binding names a Network, and register() tracks Wi-Fi ones only, so binding says "reach this through the Wi-Fi's routing table" — right for a receiver on the Wi-Fi, wrong for one on any other directly connected interface. Ethernet in a dock or on a TV device, USB or Wi-Fi tethering, a VPN: there an unbound socket is routed to the correct interface by destination, while a bound one is pinned to the Wi-Fi and fails. Binding earns its keep in exactly one case — the receiver is on the Wi-Fi and the Wi-Fi is not the default network — and that case is what isInBoundNetwork() tests, with the prefix from LinkProperties and the same sameSubnet() the reconnect loop uses. An unresolvable host, an IPv6 address or a missing prefix all mean "do not bind": what cannot be shown to be inside stays outside. The SSDP socket is the exception and binds unconditionally, because its target is the multicast group 239.255.255.250, which lies in no subnet — there the binding is the interface choice.

A binding the system refuses leaves the socket unbound. A VPN that applies to this app and is not bypassable, which is the default for WireGuard, OpenVPN and most commercial VPNs, makes Android refuse a binding to any other network with EPERM. Telnet, HTTP and the scan would then fail on every attempt, where 1.6.1, which never bound, got through whenever the VPN excluded the LAN. So refusedByVpn() catches exactly that errno and lets the caller carry on unbound; any other failure is still thrown. The binding itself is asked rather than "is a VPN active", because a bypassable VPN accepts it — there the socket stays on the Wi-Fi even if the VPN tunnels the LAN, and SSDP keeps choosing its interface. openConnection() cannot catch anything, since Network.openConnection() binds only when it connects, so it binds a throwaway socket first and gets the same answer. The log records the change only, once each way, because a sweep asks about a thousand times and the feedback report carries the last 25 lines. Derived from how netd checks network selection, not verified on a device — WireGuard with the LAN excluded is the test.

What the binding cannot do is make an unreachable address reachable. With no Wi-Fi the socket stays unbound and follows the default route; beside active mobile data that is the mobile network, where a LAN address cannot arrive. bind() tolerates that as it always has — refusing there would take every caller out of the game, and a one-off HTTP scrape that times out is nobody's problem. The reconnect loop is, because it repeats forever: it paid the full AVR_CONNECT_TIMEOUT plus about two seconds of checkAddress() ping and port timeouts every 16 s for as long as the Wi-Fi stayed away.

So the loop asks first, and it asks about the address: LocalNetwork.mayConnect(connectionConfig.getIP()) — a bound Wi-Fi, or the address lies in a subnet this device is directly attached to, or the Use mobile network preference is on. Otherwise the round is skipped whole, checkAddress() included. It still sets Reachable false, because the fallthrough is what makes Connected defined, and the ConfigurationAssistant hint for "no Wi-Fi" hangs on that.

Three things about that question are deliberate:

  • It asks about the address, not about the transport of the default network. An unbound socket reaches the directly-connected subnet of every interface, whatever the default route is — that is the whole reason Local Network Protection had to be invented. A gate on "the default network is cellular" would therefore have refused three working setups: Ethernet on the device beside active mobile data, an Ethernet link without WAN (which never becomes the default network, and which register() does not report either, since it asks for TRANSPORT_WIFI only), and the device's own hotspot, whose interface is not a Network at all. In all three the receiver is reachable, and refusing would have left it unreachable for good with no dialog able to explain why. The address answers all three without a case distinction: isDirectlyConnected() walks NetworkInterface — java.net, not the ConnectivityManager, precisely because the interfaces that matter here are the ones that are no Network — and compares prefixes. LocalNetworkTest pins that arithmetic; it is the one part of this area a JVM test can reach.
  • Every uncertainty answers "try anyway". An unresolvable name, IPv6, an enumeration that throws: the gate saves timeouts, so in doubt it must not prevent anything. Same for the two bypasses of the preference — no Application context, which is what keeps HTTPSupportTest and ConnectorTest able to reach their own sockets, and an emulator, where the network detection has nothing to go on (ConfigurationAssistant.checkStatus and AVRScanner.scan make the same exception). The flip side: on an emulator neither the skipped round nor the Use mobile network switch, the "Wi-Fi is not active" hint or the scan's "no Wi-Fi address" error can be reached — the scan sweeps a hard-coded 192.168.10.1/24 instead. All four need a device. EmulationDetector goes by Build.HARDWARE (ranchu, or goldfish on the old images) and is therefore true on every Android Studio emulator, whatever its ABI.
  • It reads boundNetwork, not StatusFlag.WLAN. The flag travels through a Handler.post() and can lag the field; a connect that would have worked must not die on a stale value. The field is the one the binding itself would use, read at the moment of the connect. A Wi-Fi the callback has not reported yet is covered twice over, because its subnet is on the interface list either way.

The switch is for one scenario and only that: a receiver reachable from outside, over a forwarded port or a VPN. ConnectionConfiguration resolves its address with InetAddress.getByName(), so a DynDNS name is a valid configuration, and a hard rule would have broken it silently. What interfaces a device actually has now rides along in every feedback report as the IPv4 line, and in the log line of a skipped round.

One thing cannot be bound: InetAddress.isReachable() offers no way to. The scan's ping may therefore still leave over the wrong interface. It is only a fast negative filter ahead of the TCP probe on port 80, so the fallback if it misbehaves on a device is to drop it, not to reach for bindProcessToNetwork().

Local Network Protection

The binding is also what Android 17 requires. Local Network Protection is mandatory at targetSdk 37, which this app now targets, and gates every socket into the local network behind ACCESS_LOCAL_NETWORK — telnet 23 and the HTTP scraping as much as the search. Without it the app is not scan-less, it is dead.

The permission is declared in the manifest and requested by AVRSettings.requestLocalNetworkPermission(), from AVRRemote.onCreate and, since recents restores whichever of the two was on top, OnScreenDisplayActivity.onCreate (once per process, one flag shared by both: on a fresh start, and on a restore after the process died — a revoke in the settings kills it — but not on a rotation, which could otherwise fire a second request beside an open system dialog; a restore while a dialog of its own was open asks again, and Android answers one of the two empty — accepted, because treating the old request as still running could leave the process never asking) and again from AVRScanner.scanIP(), because the scan is reachable from the options menu and the setup assistant without AVRRemote having started. There is no rationale dialog of the app's own — the reasons are in the comment at the request. On a grant the connection is marked as distrusted (ActiveHandler.distrustConnection()), from AVRRemote and OnScreenDisplayActivity alike, because the attempts made without it went nowhere — the result always arrives before onResume, whose contextResumed() then rebuilds it once; reconnecting from the result as well started two connectors 5 ms apart; and if no address is configured yet, the grant came from the setup's scan, so the assistant reopens its IP dialog.

LNP blocks silently. Measured on a Pixel 8 with the restriction forced on: without the permission the socket does not fail, it is swallowed — InetAddress.isReachable() says false and connect() to port 23 ends in a SocketTimeoutException after 2.5 s, from the correct source address. There is no SecurityException to catch and nothing in the failure that names a permission. Left alone, the app would show its ordinary "not reachable" state and retry forever, which reads as "receiver switched off or wrong IP" — the one diagnosis that sends a user looking in entirely the wrong place. Hence two deliberate hints:

  • ConfigurationAssistant.checkStatus() explains the block once the connection attempt has failed, with a button to the app info page — the only way back after a final refusal; the main menu has the same entry; and
  • AVRScanner.scan() refuses to start and says why, instead of letting the user watch a progress dialog for ten seconds before "no receiver found".

The first is where users actually meet it. ConfigurationAssistant.checkStatus() used to see WLAN true and Reachable false and announce that the configured address was invalid, offering a scan that could not work either — while the address was perfectly correct. Under LNP Reachable is always false, because both the ping and the port-80 probe go nowhere. That is the dialog a user sees at startup, so that is where the explanation belongs.

Nothing raises a dialog from AVRRemote.onCreate any more, including the rationale that shouldShowRequestPermissionRationale() asks for. The connection progress dialog and the assistant open on top of it within seconds, so it was never seen — and because the old code called requestPermissions() from that dialog's button, the permission was never actually requested at all. Asking directly, as the POST_NOTIFICATIONS path beside it does, is what makes the system dialog appear.

All of it is gated on AVRSettings.isLocalNetworkBlocked(), which asks whether LNP applies to this build — the device is Android 17 and getApplicationInfo().targetSdkVersion is 37 — not merely whether the permission is missing. That was written while the target was still 36, where the permission is absent without consequence and a warning about it would have been simply wrong; reading the target from the running package rather than from a constant is what armed the hints by itself on the day build.gradle moved to 37. AVRSettings.requestLocalNetworkPermission() carries the same condition, so the app does not spend the user's refusals — the second one is final — on a permission that cannot yet do anything.

To exercise the blocked state now, take the permission away:

adb shell pm revoke de.pskiwi.avrremote android.permission.ACCESS_LOCAL_NETWORK

pm revoke keeps the permission's USER_SET/USER_FIXED flags from earlier answers, and so does pm grant. A test that wants Android's own sequence — first refusal asks again, second is final, the back key counts as a refusal — has to start from pm clear-permission-flags de.pskiwi.avrremote android.permission.ACCESS_LOCAL_NETWORK user-set user-fixed and grant through the app info page, not pm grant. Without that, a single refusal can already come back as final.

Measured on a Pixel 8 that way in September 2026: Reconnector:reachable ... : false while the receiver is plainly there, the assistant explains it instead of blaming the address, and the scan stops with the same explanation. Granting it again produces reachable true and a reconnect within the next cycle. The older route, adb shell am compat enable RESTRICT_LOCAL_NETWORK, forces the restriction itself but not the hints, which are gated on targetSdkVersion — it was the way to see the blocking before the target moved, and it is the weaker test now.

Searching instead of sweeping

scan/SSDPDiscovery sends an M-SEARCH to 239.255.255.250:1900 (three times, ~800 ms apart, collecting for three seconds — UDP is allowed to lose packets) and returns the addresses that answered, each with the LOCATIONs it named. Every candidate then goes through the existing AVRTargetTester.testAddress(), which is what keeps printers, TVs and routers — they all answer ssdp:all — out of the result, and is why nothing else about the scan had to change.

Separately from the search, http/DeviceDescription fetches the receiver's UPnP description once an hour from http://<ip>:8080/description.xml — hard-coded port, because port 80 answers that path with a 404 on an AVR-3310 and the authoritative LOCATION exists only during a scan (which does use it, see below). It runs on the background thread in StatusAreaManager that already fetches the XML state, and on Reachable rather than only on Connected: a receiver that answers ping and port 80 but holds its single control channel is exactly the state field reports come from, and the description is what says which device is really there — as opposed to which one the user picked from the list of 60. It lands in the feedback report. serialNumber and UDN are deliberately not read: both carry the device's MAC, and a report travels by mail.

The scan reads the same description for every receiver it confirms, there from the LOCATIONs the M-SEARCH replies carried and only then from port 8080 (a sweep hit knows nothing else) — at most three URLs per device. The hit is recorded before the fetch and only relabelled after it, so a thread still fetching when JOIN_TIMEOUT runs out loses the label, not the receiver. A LOCATION is only taken when its host is the reply's sender address — SSDPDiscovery.fromSender() — because anything on the network can answer. That keeps foreign addresses out of the request itself and no more: HTTPSupport follows redirects and reads without a size limit, so the sender can still point onwards from its own URL, exactly as it could on the hourly 8080 fetch — after passing AVRTargetTester. The result labels the entry in the selection list (Denon AVR-3310 – 192.168.10.30) and, during setup, becomes the model suggestion that ConfigurationAssistant asks the user to confirm. Setup asks for the address first and the model second; an address with a model never chosen (the dialog dismissed, or the address typed into the settings) is caught by ConfigurationAssistant.checkModel() on every onResume of AVRRemote.

Both searches hand their addresses to the same AVRScanner.testAll(), which fans them out over SCAN_THREADS threads. That matters more for SSDP than it looks: a candidate costs up to four connect timeouts, a confirmed one its description fetches on top, so testing a household's worth of UPnP devices one after another would take longer than the whole sweep it is supposed to replace. A hit carries the way it was found (FoundBy.SSDP or FoundBy.SWEEP) into the selection list, because the two say different things — SSDP means the device announced itself as a UPnP device, the sweep only means the right ports are open.

No MulticastLock is needed: replies to M-SEARCH come back unicast. A lock only gates incoming multicast, i.e. unsolicited NOTIFY. If a device turns out to receive nothing, WifiManager.createMulticastLock() is the next step — and ACCESS_WIFI_STATE, dropped from the manifest when nothing used WifiManager any more, comes back with it.

The subnet sweep stays as the fallback: 254 addresses × up to four TCP connects, now driven by the prefix length from LocalNetwork.getIPv4() rather than by a string comparison against 255.255.255.0, so /25…/30 work instead of being refused. Under LNP a sweep is also precisely the behaviour that makes the permission expensive to justify, which is the other reason SSDP goes first.