BiglySoftware / BiglyBT

Feature-filled Bittorrent client based on the Azureus open source project
https://www.biglybt.com
GNU General Public License v2.0
1.55k stars 153 forks source link

Broken startup after update to 2.9.0.1_B27 #2421

Closed lislei closed 2 years ago

lislei commented 2 years ago

Hello Parg, after doing the auto update today Bigly doesn't start up a GUI on my machine.

parg commented 2 years ago

No debug? What if you run it via

BiglyBT-console.exe

?

lislei commented 2 years ago

The alert logs ends with a line referring to https://wiki.biglybt.com/w/Vuze_disappears

Debug log ends with

[19.01.22 18:20] Log File Opened for BiglyBT 2.9.0.1_B27
[18:20:46] [stderr] DEBUG::Wed Jan 19 18:20:46 CET 2022::com.biglybt.core.util.NetUtils$1::run::121:
[18:20:46] [stderr]   Network interface enumeration took 671: increased refresh frequency to 120000ms
[18:20:46] [stderr]     run (NetUtils.java:192), run (AEThread2.java:317)
[18:20:46] [stderr] DEBUG::Wed Jan 19 18:20:46 CET 2022::com.biglybt.core.util.DebugLight::printStackTrace::35:
[18:20:46] [stderr]   java.lang.NullPointerException
    at java.net.NetworkInterface.getInterfaceAddresses(Unknown Source)
    at com.biglybt.core.security.impl.SESecurityManagerImpl$ClientSecurityManager.filterNetworkInterfaces(SESecurityManagerImpl.java:1967)
    at com.biglybt.core.util.NetUtils$1.run(NetUtils.java:162)
    at com.biglybt.core.util.NetUtils$2.run(NetUtils.java:192)
    at com.biglybt.core.util.AEThread2$threadWrapper.run(AEThread2.java:317)
[18:20:46] [stderr] 
lislei commented 2 years ago

Running via BiglyBT-console.exe produces the same error output to console.

lislei commented 2 years ago

I did however update Java 8 four days ago. It might be an issue related to the security manager like the stactrace says.

parg commented 2 years ago

Hmm, I don't think that debug log would directly prevent the UI from starting :(

Can you replace the BiglyBT.jar with B26 and see if that helps? Download from

https://biglybt-files.s3.amazonaws.com/core/BiglyBT2901-B26-signed.jar

and rename to BiglyBT.jar

lislei commented 2 years ago

Reverting the jar made the GUI show up.

Relevant debug log reads:

[19.01.22 21:53] Log File Opened for BiglyBT 2.9.0.1_B26
[21:53:40] [stderr] DEBUG::Wed Jan 19 21:53:40 CET 2022::com.biglybt.core.util.NetUtils$1::run::121:
[21:53:40] [stderr]   Network interface enumeration took 763: increased refresh frequency to 120000ms
[21:53:40] [stderr]     run (NetUtils.java:192), run (AEThread2.java:317)
[21:53:41] [stderr] DEBUG::Wed Jan 19 21:53:41 CET 2022::com.biglybt.platform.win32.access.impl.AEWin32AccessImpl::getAllDrives::645:
[21:53:41] [stderr]   Not enumerating system drives as it crashed last time we tried
[21:53:41] [stderr]     run (Win32UIEnhancer.java:413), run (AEThread2.java:317)

then some tracker logging followed by some more errors:

[21:53:47] [stderr] INFO: Native CPUID library jcpuid-x86-windows.dll loaded from resource
[21:53:47] [stderr] INFO: Loaded library: jar:file:/C:/Users/Leif/AppData/Roaming/BiglyBT/plugins/azneti2phelper/jbigi-win_0.4.jar!/jbigi-windows-corei_64.dll
[21:53:47] [stderr] INFO: Native BigInteger library jbigi-windows-corei_64.dll loaded from resource
[21:53:49] [stderr] Warning - No client apps or router console configured - we are just a router
[21:53:56] [stderr] java.net.SocketException: Network is unreachable: connect
[21:53:56] [stderr]     at sun.nio.ch.Net.connect0(Native Method)
[21:53:56] [stderr]     at sun.nio.ch.Net.connect(Unknown Source)
[21:53:56] [stderr]     at sun.nio.ch.DatagramChannelImpl.connect(Unknown Source)
[21:53:56] [stderr]     at lbms.plugins.mldht.kad.utils.AddressUtils.getDefaultRoute(AddressUtils.java:221)
[21:53:56] [stderr]     at lbms.plugins.mldht.kad.DHT.start(DHT.java:734)
[21:53:56] [stderr]     at lbms.plugins.mldht.azureus.MlDHTPlugin$9.runSupport(MlDHTPlugin.java:670)
[21:53:56] [stderr]     at com.biglybt.core.util.AsyncDispatcher$1.run(AsyncDispatcher.java:168)
[21:53:56] [stderr]     at com.biglybt.core.util.AEThread2$threadWrapper.run(AEThread2.java:317)
[21:53:57] [stderr] DEBUG::Wed Jan 19 21:53:57 CET 2022  Premature fixup?; getFiles (DownloadManagerStateImpl.java:4608), makeSureFilesFacadeFilled (DownloadManagerController.java:3136), getDiskManagerFileInfoSet (DownloadManagerController.java:2227), getDiskManagerFileInfoSet (DownloadManagerImpl.java:3933), getSkippedFileSetSize (DownloadManagerStatsImpl.java:1569), getRemainingExcludingDND (DownloadManagerStatsImpl.java:1604), refresh (SizeItem.java:79), invokeCellRefreshListeners (TableColumnImpl.java:989), refresh (TableCellSWTBase.java:862), refresh (TableRowSWTBase.java:414)
[21:53:58] [stderr] DEBUG::Wed Jan 19 21:53:58 CET 2022  Premature fixup?; getFiles (DownloadManagerStateImpl.java:4608), makeSureFilesFacadeFilled (DownloadManagerController.java:3136), getDiskManagerFileInfoSet (DownloadManagerController.java:2227), getDiskManagerFileInfoSet (DownloadManagerImpl.java:3933), getPrimaryFile (DownloadManagerStateImpl.java:1769), getContentImage (TorrentUIUtilsV3.java:402), cellPaint (ColumnThumbAndName.java:326), invokeSWTPaintListeners (TableCellSWTBase.java:438), doPaint (TableCellSWTBase.java:1278), swt_paintCell (TableRowPainted.java:676)
[21:53:58] [stderr] DEBUG::Wed Jan 19 21:53:58 CET 2022  Premature fixup?; getFiles (DownloadManagerStateImpl.java:4608), makeSureFilesFacadeFilled (DownloadManagerController.java:3136), getDiskManagerFileInfoSet (DownloadManagerController.java:2227), getDiskManagerFileInfoSet (DownloadManagerImpl.java:3933), getPrimaryFile (DownloadManagerStateImpl.java:1769), getContentImage (TorrentUIUtilsV3.java:402), cellPaint (ColumnThumbAndName.java:326), invokeSWTPaintListeners (TableCellSWTBase.java:438), doPaint (TableCellSWTBase.java:1278), swt_paintCell (TableRowPainted.java:676)
[21:53:58] [stderr] DEBUG::Wed Jan 19 21:53:58 CET 2022  Premature fixup?; getFiles (DownloadManagerStateImpl.java:4608), makeSureFilesFacadeFilled (DownloadManagerController.java:3136), getDiskManagerFileInfoSet (DownloadManagerController.java:2227), getDiskManagerFileInfoSet (DownloadManagerImpl.java:3933), getPrimaryFile (DownloadManagerStateImpl.java:1769), getContentImage (TorrentUIUtilsV3.java:402), cellPaint (ColumnThumbAndName.java:326), invokeSWTPaintListeners (TableCellSWTBase.java:438), doPaint (TableCellSWTBase.java:1278), swt_paintCell (TableRowPainted.java:676)
[21:53:58] [stderr] DEBUG::Wed Jan 19 21:53:58 CET 2022  Premature fixup?; getFiles (DownloadManagerStateImpl.java:4608), makeSureFilesFacadeFilled (DownloadManagerController.java:3136), getDiskManagerFileInfoSet (DownloadManagerController.java:2227), getDiskManagerFileInfoSet (DownloadManagerImpl.java:3933), getPrimaryFile (DownloadManagerStateImpl.java:1769), getContentImage (TorrentUIUtilsV3.java:402), cellPaint (ColumnThumbAndName.java:326), invokeSWTPaintListeners (TableCellSWTBase.java:438), doPaint (TableCellSWTBase.java:1278), swt_paintCell (TableRowPainted.java:676)
[21:53:58] [stderr] DEBUG::Wed Jan 19 21:53:58 CET 2022  Premature fixup?; getFiles (DownloadManagerStateImpl.java:4608), makeSureFilesFacadeFilled (DownloadManagerController.java:3136), getDiskManagerFileInfoSet (DownloadManagerController.java:2227), getDiskManagerFileInfoSet (DownloadManagerImpl.java:3933), getPrimaryFile (DownloadManagerStateImpl.java:1769), getContentImage (TorrentUIUtilsV3.java:402), cellPaint (ColumnThumbAndName.java:326), invokeSWTPaintListeners (TableCellSWTBase.java:438), doPaint (TableCellSWTBase.java:1278), swt_paintCell (TableRowPainted.java:676)
[21:53:58] [stderr] DEBUG::Wed Jan 19 21:53:58 CET 2022  Premature fixup?; getFiles (DownloadManagerStateImpl.java:4608), makeSureFilesFacadeFilled (DownloadManagerController.java:3136), getDiskManagerFileInfoSet (DownloadManagerController.java:2227), getDiskManagerFileInfoSet (DownloadManagerImpl.java:3933), getPrimaryFile (DownloadManagerStateImpl.java:1769), getContentImage (TorrentUIUtilsV3.java:402), cellPaint (ColumnThumbAndName.java:326), invokeSWTPaintListeners (TableCellSWTBase.java:438), doPaint (TableCellSWTBase.java:1278), swt_paintCell (TableRowPainted.java:676)
[21:53:58] [stderr] DEBUG::Wed Jan 19 21:53:58 CET 2022  Premature fixup?; getFiles (DownloadManagerStateImpl.java:4608), makeSureFilesFacadeFilled (DownloadManagerController.java:3136), getDiskManagerFileInfoSet (DownloadManagerController.java:2227), getDiskManagerFileInfoSet (DownloadManagerImpl.java:3933), getPrimaryFile (DownloadManagerStateImpl.java:1769), getContentImage (TorrentUIUtilsV3.java:402), cellPaint (ColumnThumbAndName.java:326), invokeSWTPaintListeners (TableCellSWTBase.java:438), doPaint (TableCellSWTBase.java:1278), swt_paintCell (TableRowPainted.java:676)
[21:53:58] [stderr] DEBUG::Wed Jan 19 21:53:58 CET 2022::com.biglybt.core.util.ThreadPool::checkWarning::368:
[21:53:58] [stderr]   Thread pool 'GetOffSWT' is full (busy=com.biglybt.ui.swt.Utils$22,com.biglybt.ui.swt.Utils$22,com.biglybt.ui.swt.Utils$22)
[21:53:58] [stderr]     run (ThreadPool.java:296), run (ThreadPool.java:213), getOffOfSWTThread (Utils.java:3879), stateChanged (MyTorrentsView.java:2713), dispatch (DownloadManagerImpl.java:164), dispatch (DownloadManagerImpl.java:1), doDispatch (ListenerManager.java:438), dispatchInternal (ListenerManager.java:520), dispatchLoop (ListenerManager.java:563), run (ListenerManager.java:366), run (AEThread2.java:317)
[21:53:59] [stderr] DEBUG::Wed Jan 19 21:53:59 CET 2022  Premature fixup?; getFiles (DownloadManagerStateImpl.java:4608), makeSureFilesFacadeFilled (DownloadManagerController.java:3136), getDiskManagerFileInfoSet (DownloadManagerController.java:2227), getDiskManagerFileInfoSet (DownloadManagerImpl.java:3933), getVisibleFiles (MyTorrentsView.java:3483), rowRefresh (MyTorrentsView.java:3472), invokeRefreshListeners (TableViewImpl.java:540), refresh (TableRowSWTBase.java:392), refresh (TableRowPainted.java:818), run (TableViewPainted.java:901)
[21:53:59] [stderr] DEBUG::Wed Jan 19 21:53:59 CET 2022  Premature fixup?; getFiles (DownloadManagerStateImpl.java:4608), makeSureFilesFacadeFilled (DownloadManagerController.java:3136), getDiskManagerFileInfoSet (DownloadManagerController.java:2227), getDiskManagerFileInfoSet (DownloadManagerImpl.java:3933), getVisibleFiles (MyTorrentsView.java:3483), rowRefresh (MyTorrentsView.java:3472), invokeRefreshListeners (TableViewImpl.java:540), refresh (TableRowSWTBase.java:392), refresh (TableRowPainted.java:818), run (TableViewPainted.java:901)
[21:53:59] [stderr] DEBUG::Wed Jan 19 21:53:59 CET 2022  Premature fixup?; getFiles (DownloadManagerStateImpl.java:4608), makeSureFilesFacadeFilled (DownloadManagerController.java:3136), getDiskManagerFileInfoSet (DownloadManagerController.java:2227), getDiskManagerFileInfoSet (DownloadManagerImpl.java:3933), getVisibleFiles (MyTorrentsView.java:3483), rowRefresh (MyTorrentsView.java:3472), invokeRefreshListeners (TableViewImpl.java:540), refresh (TableRowSWTBase.java:392), refresh (TableRowPainted.java:818), run (TableViewPainted.java:901)
[21:53:59] [stderr] DEBUG::Wed Jan 19 21:53:59 CET 2022  Premature fixup?; getFiles (DownloadManagerStateImpl.java:4608), makeSureFilesFacadeFilled (DownloadManagerController.java:3136), getDiskManagerFileInfoSet (DownloadManagerController.java:2227), getDiskManagerFileInfoSet (DownloadManagerImpl.java:3933), getVisibleFiles (MyTorrentsView.java:3483), rowRefresh (MyTorrentsView.java:3472), invokeRefreshListeners (TableViewImpl.java:540), refresh (TableRowSWTBase.java:392), refresh (TableRowPainted.java:818), run (TableViewPainted.java:901)
[21:53:59] [stderr] DEBUG::Wed Jan 19 21:53:59 CET 2022  Premature fixup?; getFiles (DownloadManagerStateImpl.java:4608), makeSureFilesFacadeFilled (DownloadManagerController.java:3136), getDiskManagerFileInfoSet (DownloadManagerController.java:2227), getDiskManagerFileInfoSet (DownloadManagerImpl.java:3933), getVisibleFiles (MyTorrentsView.java:3483), rowRefresh (MyTorrentsView.java:3472), invokeRefreshListeners (TableViewImpl.java:540), refresh (TableRowSWTBase.java:392), refresh (TableRowPainted.java:818), run (TableViewPainted.java:901)
[21:54:05] [stderr] DEBUG::Wed Jan 19 21:54:05 CET 2022::com.biglybt.core.download.impl.DownloadManagerController::filesExist::2181:
[21:54:05] [stderr]   Accessing 'D:\path\torrent.name' in 'torrent.name' took 3309ms - possibly offline
[21:54:05] [stderr]     filesExist (DownloadManagerImpl.java:2061), initialize (DownloadManagerImpl.java:2328), initialize (DownloadImpl.java:319), initialize (RankCalculatorReal.java:569), process (StartStopRulesDefaultPlugin.java:1773), run (StartStopRulesDefaultPlugin.java:668), run (AEThread2.java:317)
[21:54:14] DEBUG::Wed Jan 19 21:54:14 CET 2022  Conflicting peer identification: unknown_client [LTEP]: "Ukjent UW 1.2.7.21" / "libtorrent/1.2.2.0" [6C6962746F7272656E742F312E322E322E30], Peer ID: 2D55573132374C2D706476384E4F6272357E7A6D
[21:54:27] [tracker] Exception while processing the Tracker Request for udp://xxxx/​announce?info_hash=h%81%26%D3%BF%B6%9D%80%DF%95L%94%BD%CF%DE%AFo%7E%96%ED&peer_id=...&supportcrypto=1&port=58625&azudp=58156&uploaded=0&downloaded=0&left=0&corrupt=0&event=started&numwant=100&no_peer_id=1&compact=1&key=4HKCXxKV&azver=3: Unknown host xxx
lislei commented 2 years ago

Updating to B27 fails again. There's a BiblyBT.exe process but nothing new in debug logs.

Killing the process and starting BiglyBT.exe again reproduces the previously mentioned debug log.

lislei commented 2 years ago

Looking at the source code of the JDK method deducts this line is the only plausible culprit.

It seems like this is already submitted and recognized as a theoretical bug in https://bugs.openjdk.java.net/browse/JDK-8023649?focusedCommentId=14116017&page=com.atlassian.jira.plugin.system.issuetabpanels%3Acomment-tabpanel#comment-14116017

parg commented 2 years ago

Very weird. I have B27 running with no problems with the latest Java:

Java 1.8.0_321 (64 bit) Oracle Corporation C:\Program Files\BiglyBT\jre

SWT v4942r22, win32, zoom=100, dpi=96 Windows 10 v10.0, amd64 (64 bit) B2.9.0.1_B27/4 az3

parg commented 2 years ago

I tried various combinations of settings but all works for me - can you copy/paste the About dialog contents here?

It seems that the BiglyBT.exe process keeps running without a UI? Perhaps this will work:

https://github.com/BiglySoftware/BiglyBT/wiki/Diagnostics#biglybt-hangs-or-is-slow-to-respondreact

lislei commented 2 years ago

When running the B27 version it doesn't register the listen port 45100.

Here's the info from B26:

Java 1.8.0_311 (64 bit)
  Oracle Corporation
c:\program files\java\jre1.8.0_311

SWT v4942r22, win32, zoom=100, dpi=144
Windows 10 v10.0, amd64 (64 bit)
B2.9.0.1_B26/4 az3
lislei commented 2 years ago

I tried changing the dpi settings to normal scale (100%), but the issue remains the same.

parg commented 2 years ago

If you have a JDK installed try running the "jvisualvm.exe" in the bin folder. If you double click on "com.biglybt.ui.Main" it will show details of BiglyBT. Then switch to the Threads tab on the right and hit the "Thread Dump" button

lislei commented 2 years ago

thread_dump1.txt

parg commented 2 years ago

Thanks - I should have figured out how that exception could cause things to hang but your thread dump has made it clear. Should be fixed in the next beta (B29)

parg commented 2 years ago

B29 is out, please give it a spin

lislei commented 2 years ago

It's alive!

Tested automatic update from B2.9.0.1_B26 to B2.9.0.1_B29, then it startet up flawlessly.

lislei commented 2 years ago

Thank you all for keeping up the good work :)

parg commented 2 years ago

Thanks for helping diagnose :)