spotupnp: volume stops working after gettime_ms() wraps (uint32 epoch ms)

[007hacky007]

Symptom

Volume control dies in both directions while everything else keeps working: volume commands from a Spotify controller are silently dropped before reaching the renderer, and local volume changes on the renderer are no longer forwarded to Spotify. Play/pause/next/seek/load are all unaffected. The problem heals by itself after up to ~49 days, or immediately on any restart or renderer re-add, which makes it look random and pretty much impossible to reproduce on demand.

What I observed

My spotupnp instance (Linux x86_64, single Hama DIT2010 renderer) had been running since Aug 10. On Aug 16 the desktop app's volume slider did nothing, although the spirc volume frame demonstrably arrived: cspot accepted it and echoed it back (the slider snaps to the device value), but no Volume[0..100] log and no SetVolume ever followed. Local volume changes on the renderer also stopped producing UPnP Volume local change lines. Restarting the very same binary fixed both directions instantly.

The timeline is what gave it away:

• device added Aug 10 20:07 (UTC+2), so VolumeStampRx/Tx were seeded with gettime_ms() - 2000 = 3,973,793,078
• epoch milliseconds crossed a multiple of 2^32 on Aug 14 13:19:55 (UTC+2)
• on Aug 16, gettime_ms() returned 163,458,864

Root cause (as far as I can tell)

gettime_ms() is epoch-based and truncated to uint32_t, so it wraps every 49.7 days. The two volume echo gates compare stamps in absolute terms:

if (now < Device->VolumeStampRx + 1000) break;                             // shadowRequest, SPOT_VOLUME
if (Volume != (int) Device->Volume && now > Master->VolumeStampTx + 1000)  // ProcessEvent, volume feedback

Once a wrap lands between the stamp and now, both comparisons invert: 163,458,864 < 3,973,794,078, so every incoming volume command is treated as an echo of a local change, and every local change is treated as an echo of our own SetVolume. Both paths are silent, and they stay wrong until now grows past the stale stamp (up to another 49 days) or until the device is re-added and the stamps are re-seeded.

Fix

Measure age by unsigned subtraction instead of comparing absolute stamps; modular arithmetic keeps now - stamp correct across the wrap, including for a genuine echo that itself straddles the wrap, and the now - 2000 seeding in AddMRDevice() also behaves under it:

if (now - Device->VolumeStampRx < 1000) break;
if (Volume != (int) Device->Volume && now - Master->VolumeStampTx > 1000)

I verified the arithmetic with a small standalone test using the captured values above plus echo-across-wrap and fresh-device cases, and confirmed on the live system that the gate was exactly where the commands died.

Open points

I kept this deliberately minimal, but the same absolute-comparison pattern exists in a couple of other places (the expiration checks in cross_net.c, and the presence check divides gettime_ms() by 1000, which makes even subtraction jump at the wrap; in the worst case that could briefly make a STOPPED device look mute to discovery). Happy to extend the patch if you think those are worth covering, or leave them alone if you prefer.

I think this patch should fix it, but I would appreciate a sanity check of the reasoning - does the analysis look right to you? If it does, this probably explains any historical "volume randomly stopped working for a few weeks, then came back on its own" reports across the UPnP bridges, since the wrap moment is global (epoch-based): every long-running instance whose renderer was added before a wrap goes deaf to volume at the same wall-clock instant.