Message "IPv4 DHT announce failed" flooding syslog #564

marcelpaulo · 2018-03-29T06:36:23Z

I've just built transmission from source (96926a8) on Xubuntu 17.10, and whenever I add a new torrent, these messages flood the syslog, even though the torrent seems to download and upload normally:

Mar 29 03:11:31 monk transmission-daemon[29519]: [2018-03-29 03:11:31.641] Suits.S07E11.XviD-AFG[eztv].avi IPv4 DHT announce failed (firewalled, 405 nodes): Resource temporarily unavailable (/home/paulo/src/Transmission/libtransmission/tr-dht.c:738)
Mar 29 03:11:37 monk transmission-daemon[29519]: [2018-03-29 03:11:37.640] Suits.S07E11.XviD-AFG[eztv].avi IPv4 DHT announce failed (firewalled, 405 nodes): Operation now in progress (/home/paulo/src/Transmission/libtransmission/tr-dht.c:738)
Mar 29 03:11:44 monk transmission-daemon[29519]: [2018-03-29 03:11:44.641] Suits.S07E11.XviD-AFG[eztv].avi IPv4 DHT announce failed (firewalled, 405 nodes): Success (/home/paulo/src/Transmission/libtransmission/tr-dht.c:738)

I had previously installed the transmission-daemon package from Ubuntu, which is currently at version 2.92-2ubuntu3.1 and these messages weren't written to the syslog.

I removed file ~/.config/transmission-daemon/dht.dat thinking that perhaps it had a different format in version 2.92-2ubuntu3.1 and it might be causing these messages, but it had no effect: the messages kept on flooding the syslog.

This is how I built transmission:

sudo apt install build-essential automake autoconf libtool pkg-config intltool libcurl4-openssl-dev libglib2.0-dev libevent-dev libminiupnpc-dev libgtk-3-dev libappindicator3-dev libsystemd-dev
git clone https://github.com/transmission/transmission Transmission
cd Transmission
git submodule update --init
mkdir build
cd build
cmake -DENABLE_GTK:BOOL=OFF ..
make
sudo make install

I then created /etc/systemd/system/transmission-daemon.service with this:

[Unit]
Description=Transmission BitTorrent Daemon
After=network.target

[Service]
User=paulo
Type=notify
ExecStart=/usr/local/bin/transmission-daemon -f --log-error
ExecStop=/bin/kill -s STOP $MAINPID
ExecReload=/bin/kill -s HUP $MAINPID

[Install]
WantedBy=multi-user.target

and started the daemon:

sudo systemctl enable transmission-daemon.service
sudo systemctl start transmission-daemon.service

Here's my ~/.config/transmission-daemon/settings.json:

{
    "alt-speed-down": 50,
    "alt-speed-enabled": false,
    "alt-speed-time-begin": 540,
    "alt-speed-time-day": 127,
    "alt-speed-time-enabled": false,
    "alt-speed-time-end": 1020,
    "alt-speed-up": 50,
    "bind-address-ipv4": "0.0.0.0",
    "bind-address-ipv6": "::",
    "blocklist-enabled": false,
    "blocklist-url": "http://www.example.com/blocklist",
    "cache-size-mb": 4,
    "dht-enabled": true,
    "download-dir": "/home/paulo/Downloads",
    "download-queue-enabled": false,
    "download-queue-size": 5,
    "encryption": 1,
    "idle-seeding-limit": 1440,
    "idle-seeding-limit-enabled": true,
    "incomplete-dir": "/home/paulo/Downloads/incomplete",
    "incomplete-dir-enabled": true,
    "lpd-enabled": false,
    "message-level": 1,
    "peer-congestion-algorithm": "",
    "peer-id-ttl-hours": 6,
    "peer-limit-global": 2000,
    "peer-limit-per-torrent": 200,
    "peer-port": 51413,
    "peer-port-random-high": 65535,
    "peer-port-random-low": 49152,
    "peer-port-random-on-start": false,
    "peer-socket-tos": "default",
    "pex-enabled": true,
    "port-forwarding-enabled": true,
    "preallocation": 1,
    "prefetch-enabled": true,
    "queue-stalled-enabled": true,
    "queue-stalled-minutes": 30,
    "ratio-limit": 10,
    "ratio-limit-enabled": true,
    "rename-partial-files": true,
    "rpc-authentication-required": false,
    "rpc-bind-address": "0.0.0.0",
    "rpc-enabled": true,
    "rpc-host-whitelist": "",
    "rpc-host-whitelist-enabled": true,
    "rpc-password": "{bdc5f3f377bd82e9a5953b81cf22638781946f30yForhzpr",
    "rpc-port": 9091,
    "rpc-url": "/transmission/",
    "rpc-username": "",
    "rpc-whitelist": "127.0.0.1",
    "rpc-whitelist-enabled": true,
    "scrape-paused-torrents-enabled": true,
    "script-torrent-done-enabled": true,
    "script-torrent-done-filename": "/home/paulo/prj/s/torre/bin/torre",
    "seed-queue-enabled": false,
    "seed-queue-size": 10,
    "speed-limit-down": 100,
    "speed-limit-down-enabled": false,
    "speed-limit-up": 100,
    "speed-limit-up-enabled": false,
    "start-added-torrents": true,
    "trash-original-torrent-files": true,
    "umask": 18,
    "upload-slots-per-torrent": 14,
    "utp-enabled": true
}

My Internet provider uses CGNAT, so it's impossible to forward any ports for IPv4 traffic. Here's my firewall config:

Status: active

To                         Action      From
--                         ------      ----
19389/tcp                  ALLOW       Anywhere                  
19393/udp                  ALLOW       Anywhere                  
51413                      ALLOW       Anywhere                  
Anywhere                   ALLOW       192.168.100.10            
5355/udp                   ALLOW       Anywhere                  
19389/tcp (v6)             ALLOW       Anywhere (v6)             
19393/udp (v6)             ALLOW       Anywhere (v6)             
51413 (v6)                 ALLOW       Anywhere (v6)             
5355/udp (v6)              ALLOW       Anywhere (v6)

I'm at a loss here. Version 2.92-2ubuntu3.1 didn't flood syslog with these messages, but 96926a8 does.

The text was updated successfully, but these errors were encountered:

marcelpaulo · 2018-03-29T07:08:46Z

This gets more puzzling to me: I disabled the firewall (sudo ufw disable), and now transmission-daemon floods the syslog with IPv4 DHT announce failed and IPv6 DHT announce failed, just like the ones I reported before.

marcelpaulo · 2018-03-29T07:53:14Z

Still investigating ... I've just built from the 2.93 tarball, and the DHT announce failed messages are not generated. So they started to be generated between the release 2.93 and master (96926a8).

marcelpaulo · 2018-03-29T09:19:20Z

Still investigating ... I observed that, in spite of DHT announce failed seem to indicate an error, torrents donwloaded and uploaded without any apparent problem, so it led me to think that it might be safe to treat those messages as debug messages, so that they don't flood the syslog when the daemon is started with --log-error. So, I changed this:

  diff --git a/libtransmission/tr-dht.c b/libtransmission/tr-dht.c
index e33aceeb7..c4d6e9940 100644
--- a/libtransmission/tr-dht.c
+++ b/libtransmission/tr-dht.c
@@ -734,7 +734,7 @@ static int tr_dhtAnnounce(tr_torrent* tor, int af, bool announce)
         }
         else
         {
-            tr_logAddTorErr(tor, "%s DHT announce failed (%s, %d nodes): %s", af == AF_INET6 ? "IPv6" : "IPv4",
+            tr_logAddTorDbg(tor, "%s DHT announce failed (%s, %d nodes): %s", af == AF_INET6 ? "IPv6" : "IPv4",
                 tr_dhtPrintableStatus(status), numnodes, tr_strerror(errno));
         }
     }

So, summarizing my final doubts:

Shouldn't these messages be treated by default as debug ?
Why releases <= 2.93 didn't show them ? I've just diffed libtransmission/tr-dht.c in 2.93 and master (96926a8), and function tr_dhtAnnounce seems to be the same in both versions (minor formatting differences). So why these messages only started to be output > 2.93 ?!
What are the consequences of ignoring these messages ?

cfpp2p · 2018-03-30T20:13:47Z

@marcelpaulo Yes, there is a bug here.
It is nothing to do with tr_dhtAnnounce()
Trunk now uses dht 0.25
The return code behavior changed.
dht_search() now returns -1 on error, 0 for duplicate search or 1 for new search.

dht_search

This schedules a search for information about the info-hash specified in
id; it returns 1 if this is a new search, and 0 if it merely reset the
timeouts for a search in progress.

--- J:/T1/DHT-implied-port-fix-020818/work/dht.c.024.c	Mon May 18 14:40:12 2015
+++ J:/T1/DHT-implied-port-fix-020818/work/dht.c.025.c	Fri Feb  9 13:44:36 2018
@@ -1239,6 +1346,8 @@
         sr = sr->next;
     }
 
+    int sr_duplicate = sr && !sr->done;
+
     if(sr) {
         /* We're reusing data from an old search.  Reusing the same tid
            means that we can merge replies for both searches. */
@@ -1288,7 +1397,11 @@
 
     search_step(sr, callback, closure);
     search_time = now.tv_sec;
-    return 1;
+    if(sr_duplicate) {
+        return 0;
+    } else {
+        return 1;
+    }
 }

jech/dht#26 (comment)

jech/dht#28 (comment)

jech/dht#26 (comment)

jech/dht@311f4ef

Kcchouette · 2020-08-25T21:57:41Z

Same problem here with 3.00 (bb6b5a0)

solsticedhiver · 2020-09-19T23:06:19Z

I got this message just because I started to use firejail.

I fixed it by adding packet to the list of allowed protocol in a .local file override, like this:

protocol unix,inet,inet6,packet

So to the ubuntu users, that might be some apparmor issue ?

Per analysis by cfpp2p (transmission#564 (comment)), a duplicate search is not an error.

jpegxguy · 2021-11-24T15:04:02Z

IT doesn't seem fixed to me. Transmission spams away
IPv4 DHT announce failed (good, 872 nodes): Connection reset by peer

and others like
IPv4 DHT announce failed (good, 872 nodes): No such file or directory/Success etc.

The fact that I get this even with "Success" description points to the fact that tr_strerror() is being called even though there was no error.

Keep in mind that even my state is good instead of firewalled

EDIT: I see the commit has been merged in February, it just doesn't seem to exist in a released version yet

oliv3r · 2022-06-06T14:02:55Z

Half a year later, I still see this spammed into logs; so still no release?

ckerr · 2022-06-06T14:33:22Z

Half a year later, I still see this spammed into logs; so still no release?

#2287 (comment)

greenpark-code · 2023-12-13T00:37:35Z

transmission-daemon V 3.00-1 on Raspberry PI OS 64 (Linux raspberrypi 6.1.21-v8+ # 1642 SMP PREEMPT Mon Apr 3 17:24:16 BST 2023 aarch64 GNU/Linux).

I was also seeing a lot of those messages watching the output of journalctl -f until I stopped the daemon, edited /etc/transmission-daemon/settings.json, set the peer-port number to the default value "peer-port": 51413 (of course I modified ufw's settings accordingly) and restarted the daemon (about two hours ago), no such messages have appeared again so far. The port number I was using previously was 61329 (not randomly generated).

I was thinking "maybe the default port number is hard-coded in the source code in a place where the actual setting should be used instead", but I've had no success searching in the code for such a bug.

I've noticed (netblue30/firejail#3636) that somebody has been seeing those error messages after changing something related with firejail.
I have not installed firejail on this raspberry pi.

greenpark-code · 2023-12-27T23:36:47Z

DHT-related errors popped up again occasionally, sometimes flooding output of journalctl -f

I've disabled DHT in transmission-daemon (through the GUI, Tools | Transmission options | Network | Enable DHT, unmarked the checkbox).

zootboy · 2023-12-28T04:19:36Z

If you want a more surgical way of dealing with the logspam, you can add the following lines to the [Service] section of your transmission daemon .service unit:

LogFilterPatterns=~IPv4 DHT announce failed
LogFilterPatterns=~IPv6 DHT announce failed

GaryElshaw · 2023-12-28T10:54:09Z

We need to try harder.

This was referenced Mar 29, 2018

"make uninstall" doesn't remove /usr/local/share/transmission #565

Closed

Build of 2.93 on Ubuntu 17.10 doesn't include systemd support #566

Closed

sergserg2 mentioned this issue Nov 21, 2019

"IPv4 DHT announce failed" flooding syslog #1059

Closed

npapke mentioned this issue Feb 6, 2021

Properly parse dht_search() #1619

Merged

livings124 closed this as completed in d2c8137 Feb 27, 2021

Akzuu pushed a commit to eltsu7/transmission that referenced this issue Apr 6, 2021

Fixes transmission#564

465800f

Per analysis by cfpp2p (transmission#564 (comment)), a duplicate search is not an error.

This comment was marked as duplicate.

Sign in to view

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Message "IPv4 DHT announce failed" flooding syslog #564

Message "IPv4 DHT announce failed" flooding syslog #564

marcelpaulo commented Mar 29, 2018

marcelpaulo commented Mar 29, 2018

marcelpaulo commented Mar 29, 2018 •

edited

Loading

marcelpaulo commented Mar 29, 2018 •

edited

Loading

cfpp2p commented Mar 30, 2018 •

edited

Loading

Kcchouette commented Aug 25, 2020

solsticedhiver commented Sep 19, 2020 •

edited

Loading

This comment was marked as duplicate.

jpegxguy commented Nov 24, 2021 •

edited

Loading

oliv3r commented Jun 6, 2022

ckerr commented Jun 6, 2022

greenpark-code commented Dec 13, 2023 •

edited

Loading

greenpark-code commented Dec 27, 2023 •

edited

Loading

zootboy commented Dec 28, 2023

GaryElshaw commented Dec 28, 2023

Message "IPv4 DHT announce failed" flooding syslog #564

Message "IPv4 DHT announce failed" flooding syslog #564

Comments

marcelpaulo commented Mar 29, 2018

marcelpaulo commented Mar 29, 2018

marcelpaulo commented Mar 29, 2018 • edited Loading

marcelpaulo commented Mar 29, 2018 • edited Loading

cfpp2p commented Mar 30, 2018 • edited Loading

Kcchouette commented Aug 25, 2020

solsticedhiver commented Sep 19, 2020 • edited Loading

This comment was marked as duplicate.

jpegxguy commented Nov 24, 2021 • edited Loading

oliv3r commented Jun 6, 2022

ckerr commented Jun 6, 2022

greenpark-code commented Dec 13, 2023 • edited Loading

greenpark-code commented Dec 27, 2023 • edited Loading

zootboy commented Dec 28, 2023

GaryElshaw commented Dec 28, 2023

marcelpaulo commented Mar 29, 2018 •

edited

Loading

marcelpaulo commented Mar 29, 2018 •

edited

Loading

cfpp2p commented Mar 30, 2018 •

edited

Loading

solsticedhiver commented Sep 19, 2020 •

edited

Loading

jpegxguy commented Nov 24, 2021 •

edited

Loading

greenpark-code commented Dec 13, 2023 •

edited

Loading

greenpark-code commented Dec 27, 2023 •

edited

Loading