Closed ferdnyc closed 2 weeks ago
Hmm!
Weird that after the restart the
{tracker} Tracker Announcer is Requesting: http://tracker.biglybt.com:6969/announce?...
line is missing after the
{tracker} Tracker Announcer is sending an update Request
The lines before the restart all have a "&numwant=0" which is odd, I'll look into that.
The calculation of "numwant" is based on limits and a few other things and if no peer connections are available then it won't ask for any peers. Check
Options->Transfer [Auto]: Max connections globally [0: unlimited]
Is it possible that the limit has been reached?
@parg
I'll check that setting (not at my computer right now). I'm sure I have it set to some value, since it's one of the ways I keep BiglyBT from completely filling the connection table in my router to the point I can't even browse the web, when it gets busy with active torrents.
I expect I have it set to 120 or so, tho maybe I turned it down at some point. I also definitely have the per-torrent limit set, to something like 25-30? I'll definitely check and report back.
But even if it's a lot lower, if it IS being hit, then seems like BiglyBT is holding a LOT of connections open for "no reason" even when relatively idle. Often when this happens, there are no other torrents actively downloading, and at most 4 or 5 actively uploading. There are a lot of torrents "idly seeding", sure, but not so's they're ever doing much.
It is POSSIBLE I have more torrents seeding than I have connections configured. So if there's some sort of 1 connection / torrent minimum, then that could be it. Otherwise, even with the occasional tracker update, it's hard to understand how it wouldn't eventually free up a connection for the download.
I was poking around a bit and added some extra counters in B20. Under stats->counters there are a few of interest:
lws.peer.count
peer.db.data.id.peer.total
peer.db.peer.count
peer.manager.peer.count
There are different ways of counting the current total number of peers. The last three of those should generally be equal although can differ momentarily. The lws.peer.count is just for interest.
You also have the "All Peers" view to see how many peers are currently connected.
So if you catch it misbehaving have a look at these things to see if any of the peer counts look weird/are at the limit.
@parg Just saw the update window, I'm about to start the process.
In the meantime, here's the settings dump I should've included originally.
I was overestimating my values a bit, actual max global connections is 80
, actual per-torrent is 20
(3
when seeding). So, a bit lower, but not so low that it should be interfering with starting torrents, I wouldn't think.
Paths, ports, certificates, hashes. etc. removed.
Settings
ASN Autocheck Performed Time=1188107206359
Auto Adjust Transfer Defaults=0
Auto Upload Speed Enabled=0
Auto Upload Speed Version=3
auto_remove_inactive_items=1
AutoSpeed Choking Ping Millis=550
AutoSpeed Latency Factor=40
AutoSpeed Max Decrement KBs=6
AutoSpeed Max Increment KBs=2
AutoSpeed Max Upload KBs=96
AutoSpeed Min Upload KBs=32
Beta Programme Enabled=1
Bias Upload Slack KBs=19
bLog.0.alert=0
bLog.0.cache=0
bLog.0.core=0
bLog.0.disk=0
bLog.0.GUI=0
bLog.0.net=0
bLog.0.nwman=0
bLog.0.peer=0
bLog.0.pieces=0
bLog.0.plug=0
bLog.0.stdout=0
bLog.0.tracker=0
br.backup.auto.enable=1
br.backup.auto.everyhours=1
br.backup.auto.retain=14
br.restore.doplugins=0
browser.internal.disable=1
Check Bind IP On Start=0
Colors.progressBar.green=144
Colors.progressBar.override=1
Colors.progressBar.red=107
config.style.forceSIValues=0
confirmationOnExit=1
Dark Misc Colors=1
Dark Table Colors=1
Default Start Torrents Stopped=1
DefaultDir.AutoUpdate=0
Delete Partial Files On Library Removal=1
diskmanager.perf.cache.enable.read=1
diskmanager.perf.cache.flushpieces=0
diskmanager.perf.cache.notsmallerthan=2048
diskmanager.perf.cache.size=32
diskmanager.perf.read.maxmb=16
diskmanager.perf.write.maxmb=8
DNS Alt Servers=
DNS Alt Servers SOCKS Enable=0
Dual IPV4 IPV6 Connection Action=2
Enable Sparse Files=1
File Max Open=320
File.move.download.removed.enabled=1
File.move.download.removed.move_partial=1
File.save.peers.enable=0
File.save.peers.max=20
File.Torrent.AutoSkipMinSizeKB=5
Gradient Fill Selection=0
Graphics Update=1
GUI Refresh=2000
GUI_SWT_bFancyTab=0
GUI_SWT_DisableAlertSliding=1
IconBar.enabled=0
IconBar.visible.play=0
Insufficient Space Download Restart Enable=1
Insufficient Space Download Restart Period=60
LAN Speed Enabled=0
Library.CatInSideBar=0
Library.LaunchWebsiteInBrowser=0
Library.showFancyMenu=0
Library.ShowTabsInTorrentView=0
Library.ShowTagButtons.Align=3
Library.ShowTagButtons.FiltersOnly=1
Library.ShowTitle=0
Library.TagGroupsInSideBar=0
list.dm.dblclick=1
Listen.Port.Randomize.Together=0
locale=en
locale.set.complete.count=2509
Logger.Enabled=1
Logging Enable=1
Logging Max Size=15
max active torrents=6
Max Download Speed KBs=8218
Max File Links Supported=1768
Max Upload Speed KBs=205
Max Upload Speed Seeding KBs=115
Max Uploads=2
Max Uploads Seeding=6
Max.Peer.Connections.Per.Torrent=20
Max.Peer.Connections.Per.Torrent.When.Seeding=3
Max.Peer.Connections.Total=80
max.uploads.when.busy.inc.min.secs=25
Message Popup Autoclose in Seconds=8
min downloads=3
MyTorrents.SplitAt=4757
NameColumn.showProgramIcon=0
network.admin.maybe.vpn.enable=0
network.max.simultaneous.connect.attempts=5
network.tcp.max.connections.outstanding=10
network.transport.encrypted.fallback.incoming=1
network.transport.encrypted.fallback.outgoing=1
Newly Seeding Torrents Get First Priority=0
Non-Public Peer Extra Connections Per Torrent=6
Peers View Show Local Peer=1
PeersColumn.showNetworkIcon=0
Pieces View Show Uploading=1
Play Download Error File=<default>
Play Download Finished File=<default>
Play File Finished File=<default>
Play Notification Added File=<default>
Plugin.azintsimpleapi.Enable=1
Plugin.azutp.utp.logging.enabled=1
Plugin.azutp.utp.prefer_utp=0
Plugin.default.pairing.enable=1
Plugin.default.pairing.explicit.enable=1
Plugin.Magnet URI Handler.MagnetPlugin.rename.using.dn=1
Plugin.Magnet URI Handler.MagnetPlugin.rename.using.dn.only.with.ext=1
Plugin.Magnet URI Handler.MagnetPlugin.timeout.secs=200
Plugin.Magnet URI Handler.MagnetPlugin.use.md.download.delay=10
Plugin.rssfeed.AutoStartManual=0
Plugin.rssfeed.KeepMax=100
Plugin.rssfeed.KeepOld=7
Plugin.rssfeed.RSSFeed.Config.netforce=1
Plugin.rssfeed.RSSFeed.Config.netforce.Public=1
Plugin.UPnP.upnp.alertdeviceproblems=1
Plugin.UPnP.upnp.alertothermappings=1
Plugin.UPnP.upnp.grabports=1
Plugin.UPnP.upnp.ignorebaddevices=0
Plugin.UPnP.upnp.refresh_on_bad_nat=1
Plugin.UPnP.upnp.releasemappings=0
Plugin.xml_http_if.Pairing Migrated=1
Plugin.xmwebui.Pairing Migrated=1
Plugin.xmwebui.Protocol=http
Prioritize Most Completed Files=1
Proxy.Check.On.Start=0
Proxy.SOCKS.ShowIcon=0
quick.view.maxkb=397
Rename Incomplete Files=1
Rename Incomplete Files Extension=.part
ReOrder Delay=0
Save Resume Interval=3
saveTo_list.max_entries=16
Search View Is Web View=0
SeedsColumn.showNetworkIcon=0
Set Completion Flag For Completed Downloads On Start=0
Sharing Disable RCM=1
Sharing Permit DHT=0
Show Downloading In Side Bar=0
Show New In Side Bar=0
Show Options In Side Bar=1
Show Status In Window Title=1
Show Swarm Tags In Overview=0
Show Timestamp For Alerts=1
Side Bar Close Position=1
Side Bar Top Level Order=1, 2, 6, 3,4,5
Sidebar.Plugin.SplitAt=7804
SpeedLimitMonitor.setting.download.limit.conf=LOW
SpeedLimitMonitor.setting.upload.limit.conf=LOW
SpeedLimitMonitor.setting.upload.used.download.mode=70
SpeedManagerAlgorithmProviderV2.intervals.between.adjust=5
SpeedManagerAlgorithmProviderV2.setting.download.max.limit=8527104
SpeedManagerAlgorithmProviderV2.setting.upload.max.limit=353536
SpeedTest Completed=1
StartStopManager_bIgnore0Peers=0
StartStopManager_bMaxDownloadIgnoreChecking=1
StartStopManager_bNewSeedsMoveTop=0
StartStopManager_bRetainForceStartWhenComplete=1
StartStopManager_bStopOnceBandwidthMet=0
StartStopManager_iFirstPriority_ignoreSPRatio=20
StartStopManager_iFirstPriority_ShareRatio=1500
StartStopManager_iIgnoreShareRatioSeedStart=35
StartStopManager_iMaxActiveTorrentsWhenSeeding=6
StartStopManager_iMaxStalledSeeding=0
StartStopManager_iMinSpeedForActiveDL=49152
StartStopManager_iMinSpeedForActiveSeeding=7168
StartStopManager_iRankType=4
Stats Graph Dividers=1
Stats Period=60
Status Area Show IPF=1
Status Area Show NAT=1
Status Area Show SR=1
Stop Ratio=2.0
Subfolder for DND Files=.AZ_EXCLUDE
subscriptions.auto.start.downloads=0
Suppress File Move Dialog=1
suppress_file_download_dialog=1
Table Header Gradient Fill=0
Table.sort.intuitive=1
tb.confirm.delete.content=2
Tracker Client Closedown Timeout=30
Tracker Client Concurrent Announce=25
Tracker Client Connect Timeout=15
Tracker Client Numwant Limit=0
Tracker Client Read Timeout=35
Tracker Client Scrape Stopped Enable=0
Tracker DNS Records Enable=0
Tracker Host Add Our Announce URLs=0
Tracker Key Enable Client=0
Tracker Log Enable=1
Tracker Max Threads=35
Tracker NAT Check Timeout=30
Tracker Network Selection Default.I2P=0
Tracker Network Selection Default.Tor=0
Tracker Poll Interval Min=121
Tracker Scrape Cache=5001
Tracker UDP Probe Enable=0
Transfer Bar Show Icon Area=0
ui.forceDorkTray=1
unix.script.lastaskversion=3
Up Rate Limits Include Protocol=1
update.autodownload=0
Use Lazy Bitfield=1
useCustomTab=0
User Mode=2
v3.Show Welcome=0
v3.topbar.height=176
Watch Torrent Folder=1
Watch Torrent Folder Interval Secs=30
Watch Torrent Folder Path Count=7
Watch Torrents Add Mode=1
window.maximized=0
window.rectangle=147,2,1129,926
Wizard Completed=1
XferStats.show.samples=0
Plugins
WebTorrent Support Plugin: 1.5.3
BiglyBT Transcoder: 2.3
mlDHT: 2.6.5
uTP Plugin: 0.6.8
Swarm Discoveries: 0.9.6
Java Scripter Plugin: 0.3.1
Embedded Media Player: 4.4
UPnP Media Server: 0.6.8
I2P Helper Plugin: 0.9.39.2.1
DorkBox-SystemTray Updater: 2.0
Rating: 1.6.7
Tor Helper Plugin: 1.2.4
BiglyBT Web Remote: 1.0.9
RSSFeed Scanner: 1.8.4
3D View: 0.5.5
Location Provider: 0.3.1
Measurement Lab (M-Lab): 0.3
Message Sync Support: 0.8.3
XML over HTTP: 2.1
Just saw the update window, I'm about to start the process.
Naturally, the B20 update immediately started downloading. (But it's only been 18 hours since my last restart, and this is the very first torrent I've downloaded in that time, so no surprise there. It's effectively an "immediately post-restart" scenario, modulo 18 hours of complete idle time.)
lws.peer.count peer.db.data.id.peer.total peer.db.peer.count peer.manager.peer.count
There are different ways of counting the current total number of peers. The last three of those should generally be equal although can differ momentarily. The lws.peer.count is just for interest.
So far, as it's coming out of restart, peer.db.data.id.peer.total
and peer.db.peer.count
are moving in lockstep. (Both settled back to 11
now, they were up to 40
+ briefly.) peer.manager.peer.count
was staying much lower, when they crept up, now that they're dropping back down they seem to be settling at its level. Right now they're 11
/11
/9
, 10
/10
/9
...
I'll look out for future issues and keep an eye on those numbers next time any crop up, thanks. Might be a day or two, might take a week to hit the problem again, depends what my activity ends up being.
What units are peer.control.wait.time
in, because this seems like a very big number!
(Aaargh, text copying isn't enabled in the counters list!)
Well, it just crested 530 billion. 530000000000
(Edit: Since disk.write.io.time
is already over 9 billion, I'm guessing those are in nanoseconds and not actually very big at all.)
yeah, nanoseconds :)
By the way, the counter that is used to enforce max-global-connections is peer.db.peer.count
Also just noticed that the stat peer.manager.peer.count
is incorrect, it is only showing leechers, not leechers+seeds. Doesn't affect anything as only for display, fixed in next beta.
@parg
So, I just started an unrelated, large-swarm torrent. It started downloading just fine, but I was able to open up the console not long after starting it (before any significant transfers began) and happened to notice one of the tracker requests that went out.
I didn't think to pause the logging or disable net
info logs. unfortunately, so it's already been pushed out of the display by the download traffic logs. But I did very clearly see that the request also contained numwant=0
. And this was for a torrent that was at 0% completion and hadn't even started transferring pieces yet. Connections had probably already started, tho, so maybe the numwant=0
just signified that its connection pool was already full?
Next beta I force numwant to be > 0 for downloads that have no peers, let's see of that helps!
I just started the B21
download, in the same session where I ran that download last night, and sho'nuff numwant=0
in the very first tracker request. So far after about 5 minutes, it hasn't started transferring. About to restart BiglyBT to kick it into action.
I'm starting to suspect that, if they're not made immediately after restart, all of my tracker requests are going out numwant=0
. And the only reason large-swarm torrents are still starting successfully in spite of that, is that those trackers — faced with lots of peers that lack pieces — decide to send peers my way anyway so I'll become part of the swarm and can share with other peers.
(Perhaps, also, it's actually peer exchange that's ultimately getting me connected to the seeds, rather than the tracker.)
It definitely seems to be a common thread that the torrents that do start transferring all have lots of peers, while the ones that don't are almost exclusively seeds. In addition to the number of seeds. (But to test that theory further I'd need to find a large-swarm torrent with no peers, only hundreds of seeds. Hard to track something like that down.)
Anyway, on to B21!
In B21:
[23:56:36.741] {tracker} Forcing tracker announce now via update (TRTrackerBTAnnouncerImpl.java:907), update (TRTrackerAnnouncerMuxer.java:1238), informStarted (DownloadManagerImpl.java:4670); | __NAME__
[23:56:36.742] {tracker} Tracker Announcer is sending a start Request; | Torrent: __NAME__
[23:56:36.743] {tracker} Tracker Announcer is Requesting: udp://tracker.XXXXX/announce?info_hash=XXXXXXXXX&peer_id=XXXXXX&supportcrypto=1&port=XXX&azudp=XXX&uploaded=0&downloaded=0&left=1877007789&corrupt=0&event=started&numwant=0&no_peer_id=1&compact=1&azver=3; | Torrent: __NAME__
[23:56:39.185] {tracker} Activating [[udp://XXX]]; | Torrent: __NAME__
[23:56:39.185] {tracker} Forcing tracker announce now via update (TRTrackerBTAnnouncerImpl.java:907), checkActivation (TRTrackerAnnouncerMuxer.java:700), perform (TRTrackerAnnouncerMuxer.java:547); | Torrent: __NAME__
[23:56:39.185] {tracker} Tracker Announcer is sending a start Request; | Torrent: __NAME__
[23:56:39.185] {tracker} Tracker Announcer is Requesting: udp://XXX?info_hash=XXX&peer_id=XXX&supportcrypto=1&port=XXX&azudp=XXX&uploaded=0&downloaded=0&left=1877007789&corrupt=0&event=started&numwant=0&no_peer_id=1&compact=1&azver=3; | Torrent: __NAME__
This is starting a large-swarm torrent (which is downloading, despite the numwant=0
s), seconds after restart into B21.
Is B21 supposed to have the "force numwant
> 0" feature in it, or is that the next-next beta?
Oh, wait, sorry, my mistake. I misinterpreted "for downloads that have no peers".
Hmm. I think a problem with that might be that downloads occasionally do have peers, just... "not enough"? (For example, the stuck-at-0% B21 beta was initially showing 17 seeds and 2 peers. Then it got up to 21/2, before I restarted BiglyBT. There always seemed to be at least one or two peers — depending if I'm included in that count — yet it still wasn't downloading.)
Of course, that was under B20, so it's still possible things have changed for the better in B21. I'll keep an eye on it.
Have you verified that you are at your peer-connection limit? To be honest, if you're at the limit you can't expect things to work smoothly...
Have you verified that you are at your peer-connection limit? To be honest, if you're at the limit you can't expect things to work smoothly...
That's peer.manager.peer.count
, right? Nowhere near the limit, right now it's hovering around 10
or so. I have Max.Peer.Connections.Per.Torrent=20
and Max.Peer.Connections.Total=80
, I've never seen peer.manager.peer.count
get much above 40
even when actively downloading. (Probably because I had 2 torrents queued, each maxed out, and then a few random stragglers on the torrents I'm seeding.)
Typically my seeding torrents don't have much activity other than immediately after completion, and anyway Max.Peer.Connections.Per.Torrent.When.Seeding=3
keeps them from taking up a lot of slots.
I think I'll raise Max.Peer.Connections.Total
back to 120
, I think 80
was an adjustment I made before I switched to fiber a few months ago. It should be able to handle more than that.
But if I'm reading all this right, I've been nowhere near the current limit at any point in all of this.
Hmm, there is
Options->Tracker->Client [Override Options]: Limit the number of peers the tracker may return
as well - what value do you have for that?
@parg
Tracker Client Numwant Limit=0
; unless that somehow doesn't equal "automatic" / "no limit" for this particular stat?
BTW, did some of the new stats get dropped back out of B22? I know you said you were going to fix one of the counters, but now I seem to be missing the peer.db.*
stats completely.
That's a really bad setting, the default is 100. Why did you change it? :)
If the stats are missing try closing and re-opening the stats view - I haven't looked but it might be a registration timing issue.
That's a really bad setting, the default is 100.
LOL. Well, that would explain it!
Why did you change it? :)
Honestly I have no idea, it's even entirely possible something stupid (but very me-typical) happened, like I accidentally tabbed to it and deleted the value, then had to come up with something to put there.
And since the only tooltip documentation is "Mode: Intermediate", I had no way of knowing (a) what the default value was, nor (b) what the setting even meant, in which case I definitely would've decided, "eh, 0 usually means unlimited/automatic, and if it didn't I'm sure the tooltip would say so..." ..._because it DOES usually mean that._
So, I agree. Terrible setting! :wink:
(At the very least, it really needs some help text.)
Actually, while we're on the subject, is there a non-zero default value that should be set for "Minimum time between tracker announces in seconds", right below it? Because, right now I also have that set at 0
(again purely out of ignorance), and it's similarly undocumented.
If you right-click on a setting there should be a "reset to default value" menu option
Now I'm suddenly wishing I didn't have my config backups rotating daily. (Vestigial paranoia from a previous system I had with a bad PSU that kept spontaneously resetting and corrupting my tags and forcing a restore from backup.) Even though I keep 30 backups, they only cover the past month.
Because now I'm really curious how long it's been set like that. I'm sure it's way more than 30 days, tho.
(Edit: Bah! I was wrong, I lowered it to only 2 weeks of daily backups. As suspected, the setting has been at 0
since at least 2024-06-09.)
If you right-click on a setting there should be a "reset to default value" menu option
Aha! There is, yes... but you have to literally right-click on THE SETTING. (As in, the label for the setting.) Because right-clicking on the spinbox (where you'd normally think to right-click, when wanting to reset the value in said spinbox) gets you a totally different (Gtk-default, looks like) context menu.
So, that's intuitive!
That setting's also weird because 100, in addition to being the default value, is also the maximum value. There's nowhere to go but down!
For the record, first torrent started after I fixed the setting:
[04:39:43.106] {tracker} Tracker Announcer is Requesting: udp://XXX:YYY?info_hash=XXXX&peer_id=XXX&supportcrypto=1&port=XXXX&azudp=XXXX&uploaded=0&downloaded=0&left=2716385399&corrupt=0&event=started&numwant=30&no_peerid=1&compact=1&azver=3; | Torrent: __NAME_\
spinbox is a native UI component so can't go around adding menu items to it
Description
I apologize for the vagueness of this report, it's as detailed as I can make it given the nature of the problem.
I've been noticing for a while now (on the order of weeks/months) that if BiglyBT has been running for some time when a new torrent is added, it may often fail to start that torrent downloading until it (BiglyBT) is restarted.
This doesn't generally affect torrents with a large number of seeds (hundreds/thousands), but it is frequently an issue for torrents with smaller seed counts — anything under 100, very roughly.
And, most crucially, it nearly always affects the BiglyBT beta update downloads, specifically.
Steps to reproduce (at least, on my system)
If BiglyBT has been running for at least a day or two, and an update notification pops up, the same scenario plays out each time: I hit "Download" and see the torrent started in my Library view, but it just sits there indefinitely with no connections opened to any of the 50/60 listed seeds. As a result, it will never download anything. Even if I leave it for hours or days. I have, in fact, left more than one torrent in that state for well over 24 hours with no change.
But the most common, reliable, and very strange aspect of this issue is that if I then restart BiglyBT — just File > Restart BiglyBT — the torrent will ALWAYS immediately connect and begin downloading as soon as the interface comes back up after restart.
As I said, BiglyBT's own updates aren't the only torrents this happens with, but they're the most consistently affected. And more importantly, I have the option enabled to exempt them from my IP filter rules, which eliminates any possibility (or, should) that the filters are blocking connections. (Plus, even when torrents are subject to my filters, those same filters would apply before and after restart. So it doesn't make sense that the restart would suddenly make them downloadable, if the issue was IP filtering.)
Further details
So, one of the recent times this happened, when the BiglyBT 3.6.0.1_B016 download failed to show any progress hours after being started, I decided to capture at least some data on the problem. So I generated and saved what little information I could think to collect. The steps I took were:
Put both sets of messages into a file, with a line of text dividing the two sessions labeled:
I don't know that there's any information in there that'd be useful in investigating the issue, but it's what I could think to collect. I'd be happy to follow any instructions provided in order to collect better data the next time a beta update stalls, which based on recent history should be the next time a beta update becomes available. (I just installed B19, after restarting BiglyBT to get it to download, which is what made me come back to these logs from a few days ago and finally open this issue.)
The logs
Here's the collected data: biglybt-update-beforeAfterRestart.txt
These logs are sanitized to the extent of my understanding regarding what in them could constitute personally identifiable data. However, it's possible I've overlooked some, or failed to realize that some unredacted piece of information could still be tied back to me. Regardless, I'm comfortable sharing them in this state.
I've redacted all instances of my unique client port IDs, all visible IP addresses (only one, not mine, presumably the other end of the connection), any session IDs (of which there was also only one), and all peer IDs, just in case any of those represented unique/trackable data. I left the data hashes that AFAICT represent the torrent, since it's a BiglyBT update and therefore not confidential data.
Each redacted value has a consistent, unique replacement. For example, every instance of the first peer ID I encountered was replaced by
**PEERID1**
, the next by**PEERID2**
. All instances of the first port number became**PORT1**
, the next**PORT2**
. You get the idea. The lone IP address is replaced everywhere withMMM.NNN.OOO.PPP
.I've preserved the full, unsanitized logs locally, if any of the redacted information is needed for troubleshooting/investigation.
System block
(This is the current version following my most recent update, so technically the issue hasn't occurred with this exact version... yet? It's been encountered in a large number of the prior beta versions.)