search

Tribler / tribler

Privacy enhanced BitTorrent client with P2P content discovery
https://www.tribler.org
GNU General Public License v3.0
4.82k stars 447 forks source link

Shutting down torrent checker takes several minutes #4758

Closed synctext closed 4 years ago

synctext commented 5 years ago

When closing Tribler. On Mac with RC1 after uptime of several days. Numerous minutes, the 'force shutdown' even kicks in.

synctext commented 5 years ago

Stuck forever it seems sometimes, has nothing to do with uptime (was only 15 minutes). Reproduced on Ubuntu 18.04.3 LTS.

INFO    1566208467.65       CreditMiningManager:344  (CreditMiningManager)  0 active download(s), 0.000 MB uploaded, 0.000 MB downloaded
INFO    1566208468.45           torrent_checker:150  (TorrentChecker)  Selected 6 new torrents to check on tracker: http://open.something/announce.php
INFO    1566208471.65       CreditMiningManager:342  (CreditMiningManager)  Downloading: 0, Uploading: 0, Stopped: 0
INFO    1566208471.65       CreditMiningManager:344  (CreditMiningManager)  0 active download(s), 0.000 MB uploaded, 0.000 MB downloaded
INFO    1566208475.65       CreditMiningManager:342  (CreditMiningManager)  Downloading: 0, Uploading: 0, Stopped: 0
INFO    1566208475.65       CreditMiningManager:344  (CreditMiningManager)  0 active download(s), 0.000 MB uploaded, 0.000 MB downloaded
INFO    1566208479.65       CreditMiningManager:342  (CreditMiningManager)  Downloading: 0, Uploading: 0, Stopped: 0
INFO    1566208479.65       CreditMiningManager:344  (CreditMiningManager)  0 active download(s), 0.000 MB uploaded, 0.000 MB downloaded
INFO    1566208483.66       CreditMiningManager:342  (CreditMiningManager)  Downloading: 0, Uploading: 0, Stopped: 0
INFO    1566208483.66       CreditMiningManager:344  (CreditMiningManager)  0 active download(s), 0.000 MB uploaded, 0.000 MB downloaded
INFO    1566208487.65       CreditMiningManager:342  (CreditMiningManager)  Downloading: 0, Uploading: 0, Stopped: 0
INFO    1566208487.65       CreditMiningManager:344  (CreditMiningManager)  0 active download(s), 0.000 MB uploaded, 0.000 MB downloaded
INFO    1566208488.45           torrent_checker:150  (TorrentChecker)  Selected 1 new torrents to check on tracker: http://open.deleted/965048/announce
INFO    1566208491.65       CreditMiningManager:342  (CreditMiningManager)  Downloading: 0, Uploading: 0, Stopped: 0
INFO    1566208491.65       CreditMiningManager:344  (CreditMiningManager)  0 active download(s), 0.000 MB uploaded, 0.000 MB downloaded
INFO    1566208504.59            LaunchManyCore:728  (TriblerLaunchMany)  tlm: early_shutdown
INFO    1566208504.59                   Session:564  (Session)  Tribler shutdown state notification:Shutting down Credit Mining...
INFO    1566208504.59       CreditMiningManager:107  (CreditMiningManager)  Shutting down CreditMiningManager
INFO    1566208504.59                   Session:564  (Session)  Tribler shutdown state notification:Shutting down Torrent Checker...
INFO    1566208506.92                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
INFO    1566208506.92                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
WARNING 1566208508.90             LibtorrentMgr:507  (LibtorrentMgr)  Handle (valid:True, metadata:False) - returning None as metainfo lookup result
WARNING 1566208508.90           torrent_checker:323  (TorrentChecker)  Got session error for URL DHT: [Failure instance: Traceback (failure with no frames): <type 'exceptions.RuntimeError'>: Metainfo lookup error]
INFO    1566208530.98                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
INFO    1566208530.98                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
INFO    1566208577.96                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
INFO    1566208577.96                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
INFO    1566208594.42                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
INFO    1566208594.42                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
INFO    1566208644.92                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
INFO    1566208644.92                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
INFO    1566208666.42                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
INFO    1566208666.42                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
INFO    1566208698.42                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
INFO    1566208698.42                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
INFO    1566208790.15                 community:61   (DiscoveryCommunity)  Dropping introduction request from (118.18.5.187, 9776): too many peers!
INFO    1566208868.04                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
INFO    1566208868.04                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
INFO    1566208916.46                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
INFO    1566208916.46                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
INFO    1566208927.93                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
INFO    1566208927.93                 community:105  (DiscoveryCommunity)  Dropping similarity response from (155.4.141.16, 40967): too many peers!
INFO    1566208973.95                   Session:564  (Session)  Tribler shutdown state notification:Shutting down Gigachannel Manager...
INFO    1566208973.95                   Session:564  (Session)  Tribler shutdown state notification:Shutting down Video Server...
INFO    1566208974.27                   Session:564  (Session)  Tribler shutdown state notification:Shutting down Version Checker...
INFO    1566208974.27                   Session:564  (Session)  Tribler shutdown state notification:Shutting down Resource Monitor...
INFO    1566208974.27                   Session:564  (Session)  Tribler shutdown state notification:Unloading Tunnel Community...
INFO    1566208974.27                connection:198  (Socks5Connection)  Closing session, reason stopping
INFO    1566208974.28                connection:198  (Socks5Connection)  Closing session, reason stopping
INFO    1566208974.28                connection:198  (Socks5Connection)  Closing session, reason unspecified
INFO    1566208974.28                connection:198  (Socks5Connection)  Closing session, reason unspecified
INFO    1566208974.29                   Session:564  (Session)  Tribler shutdown state notification:Shutting down TrustChain Community...
INFO    1566208974.32                   Session:564  (Session)  Tribler shutdown state notification:Shutting down IPv8...
INFO    1566208974.33                   Session:564  (Session)  Tribler shutdown state notification:Saving configuration...
INFO    1566208974.33                   Session:564  (Session)  Tribler shutdown state notification:Checkpointing Downloads...
INFO    1566208974.91                   Session:564  (Session)  Tribler shutdown state notification:Shutting down Downloads...
INFO    1566208974.93                   Session:564  (Session)  Tribler shutdown state notification:Shutting down Network...
INFO    1566208974.93            LaunchManyCore:813  (TriblerLaunchMany)  tlm: network_shutdown
INFO    1566208974.93            LaunchManyCore:816  (TriblerLaunchMany)  tlm: Number of threads still running 3
INFO    1566208974.93            LaunchManyCore:818  (TriblerLaunchMany)  tlm: Thread still running=MainThread, daemon=False, instance=<_MainThread(MainThread, started 139877665118016)>
INFO    1566208974.93            LaunchManyCore:818  (TriblerLaunchMany)  tlm: Thread still running=PoolThread-twisted.internet.reactor-0, daemon=False, instance=<Thread(PoolThread-twisted.internet.reactor-0, started 139876884281088)>
INFO    1566208974.93            LaunchManyCore:818  (TriblerLaunchMany)  tlm: Thread still running=PoolThread-twisted.internet.reactor-1, daemon=False, instance=<Thread(PoolThread-twisted.internet.reactor-1, started 139876875888384)>
INFO    1566208974.93                   Session:564  (Session)  Tribler shutdown state notification:Shutting down Libtorrent Manager...
INFO    1566208974.93                   Session:564  (Session)  Tribler shutdown state notification:Waiting for Libtorrent to finish...
INFO    1566208974.94                   Session:564  (Session)  Tribler shutdown state notification:Shutting down Metadata Store...
INFO    1566208974.94                   Session:564  (Session)  Tribler shutdown state notification:Shutting down API Manager...
INFO    1566208974.95     event_request_manager:79   (TriblerGUI)  Got Tribler core error: 2
INFO    1566208974.95     event_request_manager:79   (TriblerGUI)  Got Tribler core error: 2
INFO    1566208975.28               run_tribler:142  (root)  Shutting down Tribler

So seems a (1566208975 - 1566208504 ) /60 = 7 minute shutdown

Screenshot from 2019-08-19 11-57-25

ichorid commented 5 years ago

I confirm that sometimes it takes a couple of minutes to shutdown the Torrent Checker on Ubuntu.

xoriole commented 5 years ago

Reproducing the issue with a test case. The following is the result of creating a bunch of random torrent checker sessions and time needed to clean them up during the shutdown.

Torrent checker session Time to clean up (seconds)
100 1.649
200 4.140
500 12.203
1000 25.256
2000 51.900
5000 104.613
ichorid commented 4 years ago

Tribler 7.5 Tried the thing by creating 10K DHT check requests. Time to shutdown after that is about 10 seconds from the moment "X" on window is clicked till the window is closed. Time to shutdown without any torrent checks is the same. Seems Asyncio and refactorings helped after all. So, closing this one.