Opened 10 years ago

Closed 10 years ago

Last modified 10 years ago

#4175 closed Bug (fixed)

very bizarre and unwieldy logfile in 2.30b2

Reported by: gunzip Owned by: jordan
Priority: Normal Milestone:
Component: libtransmission Version: 2.22+
Severity: Normal Keywords:
Cc:

Description

on a multi-tracker torrent with one of the trackers down (not uncommon), i'm seeing a copious amount of logfile output such as:

[17:37:26.791]  Retrying scrape in 1302386280 seconds. (announcer.c:1188)
[17:37:27.791]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:27.791]  Retrying scrape in 1302386300 seconds. (announcer.c:1188)
[17:37:28.792]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:28.792]  Retrying scrape in 1302386300 seconds. (announcer.c:1188)
[17:37:29.792]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:29.792]  Retrying scrape in 1302386310 seconds. (announcer.c:1188)
[17:37:31.792]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:31.793]  Retrying scrape in 1302386310 seconds. (announcer.c:1188)
[17:37:32.793]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:32.793]  Retrying scrape in 1302386280 seconds. (announcer.c:1188)
[17:37:33.793]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:33.793]  Retrying scrape in 1302386310 seconds. (announcer.c:1188)
[17:37:34.794]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:34.794]  Retrying scrape in 1302386310 seconds. (announcer.c:1188)
[17:37:35.794]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:35.794]  Retrying scrape in 1302386280 seconds. (announcer.c:1188)
[17:37:36.794]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:36.794]  Retrying scrape in 1302386270 seconds. (announcer.c:1188)
[17:37:37.795]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:37.795]  Retrying scrape in 1302386300 seconds. (announcer.c:1188)
[17:37:38.795]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:38.795]  Retrying scrape in 1302386280 seconds. (announcer.c:1188)
[17:37:39.795]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:39.795]  Retrying scrape in 1302386300 seconds. (announcer.c:1188)
[17:37:41.796]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:41.796]  Retrying scrape in 1302386290 seconds. (announcer.c:1188)
[17:37:42.796]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:42.796]  Retrying scrape in 1302386320 seconds. (announcer.c:1188)
[17:37:43.796]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:43.796]  Retrying scrape in 1302386320 seconds. (announcer.c:1188)
[17:37:44.797]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:44.797]  Retrying scrape in 1302386300 seconds. (announcer.c:1188)
[17:37:45.797]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:45.797]  Retrying scrape in 1302386280 seconds. (announcer.c:1188)
[17:37:46.798]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:46.798]  Retrying scrape in 1302386330 seconds. (announcer.c:1188)
[17:37:47.798]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:47.798]  Retrying scrape in 1302386310 seconds. (announcer.c:1188)
[17:37:48.798]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:48.798]  Retrying scrape in 1302386320 seconds. (announcer.c:1188)
[17:37:49.799]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:49.799]  Retrying scrape in 1302386330 seconds. (announcer.c:1188)
[17:37:50.799]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:50.799]  Retrying scrape in 1302386300 seconds. (announcer.c:1188)
[17:37:51.799]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:51.799]  Retrying scrape in 1302386330 seconds. (announcer.c:1188)
[17:37:53.800]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)
[17:37:53.800]  Retrying scrape in 1302386290 seconds. (announcer.c:1188)
[17:37:54.800]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1179)

the frequency of the messages is excessive, also 1302386290 seconds is about 42 years, so it's informing that

Retrying scrape in 42 years ?

Change History (9)

comment:1 Changed 10 years ago by jordan

you've been finding the strangest issues lately... thanks for doing all this testing ;)

My first thought is maybe there's a conversion error taking place between the function that returns a time_t and the local variable that is an int. does r12340 fix the problem?

comment:2 Changed 10 years ago by gunzip

no, r12340 gives same behavior. btw, i have the message level set to the default value of 2.

also if i stop the torrent, this blizzard of repetitive logile entries continues and my only recourse is to exit the daemon.

comment:3 Changed 10 years ago by jordan

well, how about r12341 then :)

comment:4 Changed 10 years ago by gunzip

sorry but r12341 didn't help. when this issue first occured i noticed unusual network activity and increased CPU load, so on hunch i tried this..

$ TR_CURL_VERBOSE=1 transmission-daemon -f
.
(wait a couple minutes)

* Re-using existing connection! (#0) with host exodus.desync.com
* Connected to exodus.desync.com (208.83.20.164) port 80 (#0)
> GET /scrape?info_hash=%b8%13%c8%d4%c1e%e4y%b1%2f%d8%10%13E%80%98q%f1%a6R HTTP/1.1
User-Agent: Transmission/2.30b2
Host: exodus.desync.com
Accept: */*
Accept-Encoding: gzip;q=1.0, deflate, identity

< HTTP/1.1 404 Not Found
< Date: Sun, 10 Apr 2011 04:30:36 GMT
< Content-Type: text/html
< Transfer-Encoding: chunked
< Connection: keep-alive
< Content-Encoding: gzip
< 
* Connection #0 to host exodus.desync.com left intact
[00:30:41.146]  Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1182)
[00:30:41.146]  Retrying scrape in 1302417050 seconds. (announcer.c:1191)

every second that block is repeated indicating that it's constantly scraping, while supposedly it retries in 1302417050 seconds.

comment:5 Changed 10 years ago by jordan

grumble :)

how about r12345?

comment:6 Changed 10 years ago by gunzip

good news with r12345 ! the logfile is back under control. most everything appears normal, but when first starting/pausing the torrent i still see:

Scrape error: Tracker gave HTTP response code 404 (Not Found) (announcer.c:1182) Retrying scrape in 1302424490 seconds. (announcer.c:1191)

but it only appears once and the logfile is no longer being bombarded with this every second.

comment:7 Changed 10 years ago by jordan

  • Milestone None Set deleted
  • Resolution set to fixed
  • Status changed from new to closed

Fixed in r12346.

This was a dumb little bug that shouldn't've taken four commits :)

comment:8 Changed 10 years ago by gunzip

yes r12346 is even better .. no more "retry in 1302424490 seconds" messages anywhere.

there is one different but related issue that is more of a typo:

libtransmission/announcer.c

968     /* schedule a reannounce */
969     interval = getRetryInterval( tier->currentTracker );
970     dbgmsg( tier, "Retrying announce in %d seconds.", interval );
971     tr_torinf( tier->tor, "Retrying scrape in %d seconds.", interval );
972     tier_announce_event_push( tier, e, tr_time( ) + interval );

line 971 should read "Retrying announce", not scrape.

comment:9 Changed 10 years ago by livings124

Fixed r12347

Note: See TracTickets for help on using tickets.