Skip to content

UPnP: cache failed XML fetches + demote routine discovery logs (#622) - #653

Merged
mrjimenez merged 1 commit into
amule-project:masterfrom
got3nks:fix/upnp-routine-log-demote
May 18, 2026
Merged

UPnP: cache failed XML fetches + demote routine discovery logs (#622)#653
mrjimenez merged 1 commit into
amule-project:masterfrom
got3nks:fix/upnp-routine-log-demote

Conversation

@got3nks

@got3nks got3nks commented May 18, 2026

Copy link
Copy Markdown
Contributor

References #622.

Bug

libupnp ThreadPoolAdd too many jobs: 100 bursts on busy LANs, even after the NT-based SSDP filter in #623. @Stoatwblr's tcpdump shows ~10-13 SSDP advertisements/sec from 5 emitters; one of them (a Zyxel mesh WAP at 192.168.11.179) announces as upnp:rootdevice (so #623's filter must let it through) but its HTTP server is unreachable, so every UpnpDownloadXmlDoc() call against it pins a libupnp worker thread for the full TCP-connect timeout. Multiple concurrent fetches from a single misbehaving device saturate libupnp's pool of 100 and trigger the warning in bursts of ~20 at long intervals.

Two separate fixes in this PR, both targeting the same issue.

1. Per-URL fetch-failure cache (load reduction)

Add a per-CUPnPControlPoint std::map<std::string, time_t> keyed on the location URL of failed UpnpDownloadXmlDoc() calls, guarded by CUPnPMutex. The discovery callback now consults ShouldSkipAdvertisementFetch() before calling UpnpDownloadXmlDoc() on UPNP_DISCOVERY_ADVERTISEMENT_ALIVE events; if the URL has failed within FAILED_FETCH_TTL_SECS (300 s) the announcement is dropped at the callback entry with no HTTP attempt. On successful fetch the entry is evicted; on failure the timestamp is refreshed.

UPNP_DISCOVERY_SEARCH_RESULT events bypass the cache entirely — those are active polls initiated by amule's own search timer and should attempt the fetch regardless. Only the passive ALIVE bursts (where the device drives the rate) get throttled.

The cache stays tiny in practice (handful of misbehaving devices per LAN) and self-prunes via the TTL expiry path on the next post-TTL fetch attempt.

2. Demote two routine log lines (noise reduction)

Two AddDebugLogLineC sites fire once per service-discovery cycle on every successful WAN-service detection — the "WAN Service Detected" line in CUPnPService::CUPnPService (UPnPBase.cpp:590) and the "Successfully retrieved SCPD Document" line in CUPnPControlPoint::Subscribe (UPnPBase.cpp:1736). Both demoted to AddDebugLogLineN — visible under Cat_UPnP=1 but no longer default-on stdout noise on every IGW re-search. #627 demoted other UPnP routine logs but missed these two.

Actionable errors ("WAN service not detected", "Error retrieving device description") stay at AddDebugLogLineC.

Risk surface

  • Cache key is the literal location URL string. Different ports on the same host (the Zyxel reporter saw :49152 and :49153) are tracked as separate entries — failures on one don't suppress fetches against the other. Matches least-surprise.
  • TTL = 5 minutes. Long enough to absorb a typical SSDP advertisement burst cycle; short enough that genuine intermittent reachability isn't blocked indefinitely.
  • SEARCH_RESULT path is untouched, so amule's periodic poll of the network still attempts every URL freshly.
  • Side cleanup in the discovery callback: collapsed three inner #if UPNP_VERSION >= 10800 / #else blocks that were duplicating identical format strings differing only by which discovery variable they read from; resolved into a single const char *location at the top of the block. The outer #if UPNP_VERSION shim for actual API differences (struct type, accessor functions) is preserved.

Reported by @Stoatwblr in #622 with tcpdump advertising-rate measurements and a full topology breakdown.

Two changes that together stop a misbehaving non-WAN device on the
LAN from saturating libupnp's internal thread pool ("ThreadPoolAdd
too many jobs: 100") and turn down the volume of the periodic
service-discovery cycle.

1. Per-URL cache for failed UpnpDownloadXmlDoc() against passive
   SSDP ALIVE announcements. A device that re-announces every few
   seconds while its HTTP server is unreachable used to pin one
   libupnp worker thread per attempt for the full TCP-connect
   timeout; with several such devices on the LAN libupnp's pool
   saturates and drops jobs.

   Add std::map<std::string, time_t> m_failedFetchCache on
   CUPnPControlPoint, guarded by a wxMutex. The discovery callback
   now consults ShouldSkipAdvertisementFetch() before calling
   UpnpDownloadXmlDoc on ALIVE events; if the location URL failed
   within FAILED_FETCH_TTL_SECS (300s) the announcement is dropped.
   On successful fetch the entry is evicted; on failure its
   timestamp is refreshed. SEARCH_RESULT events bypass the cache
   since those are active polls initiated from amule's own timer.

   Side effect: the inner #if UPNP_VERSION >= 10800 / #else dance
   around the UpnpDownloadXmlDoc call and the per-message format
   strings collapses since location is now resolved once into a
   single const char*. Removes one redundant 'int ret;' from the
   legacy < 10800 branch that's no longer needed.

2. Demote two AddDebugLogLineC sites that fire once per service-
   discovery cycle on every successful detection -- the
   "WAN Service Detected" line in CUPnPService::CUPnPService and
   the "Successfully retrieved SCPD Document" line in
   CUPnPControlPoint::Subscribe. With amule's periodic re-search
   these flood stdout every few minutes on any working IGW;
   AddDebugLogLineN keeps them available under Cat_UPnP=1 without
   the default-on noise. The actionable error log levels (WAN
   service not detected, errors retrieving descriptions) are left
   at AddDebugLogLineC.

Reported by @Stoatwblr in amule-project#622 with tcpdump showing the LAN
emitting ~10-13 SSDP advertisements/sec from 5 devices, one of
which is unreachable. The pool error fires in bursts of ~20 at
long intervals -- consistent with the cache refresh cycle for an
unreachable rootdevice.
@got3nks got3nks mentioned this pull request May 18, 2026
@mrjimenez
mrjimenez merged commit 129ba0d into amule-project:master May 18, 2026
12 checks passed
@got3nks
got3nks deleted the fix/upnp-routine-log-demote branch May 22, 2026 13:51
mrjimenez pushed a commit to mrjimenez/amule that referenced this pull request Jul 28, 2026
…e-project#662)

The /eMule/CreateSparseFiles preference was EC-wired and settable from the Web UI but had no control in amule or amuleGUI, so hand-editing amule.conf was the only way to change it. Add a checkbox on the Files preferences page and move the pref from the untracked s_MiscList into the standard NewCfgItem/Cfg_Bool binding used by every sibling control. The setting only does real work when the core runs on Windows -- on POSIX both branches create the part file identically -- so the tooltip documents that, and the monolithic non-Windows build (where inertness is a compile-time certainty) hides the control after creation, keeping the binding intact so the value still round-trips through the config and EC. Closes amule-project#653.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants