4.2.x high RAM memory usage due to HTTPS tracker announces for some users

[p43b1]

Please provide the following information

qBittorrent version and Operating System

4.2.2 Windows 10

If on linux, libtorrent-rasterbar and Qt version

(type here)

What is the problem

Excessively high RAM memory usage compared to 4.2.0

320MB after continuously running for two weeks compared to 2.5GB after running for 3 hours with the same of downloading/uploading torrents.

4.2.2 RAM USAGE

4.2.2 STATISTICS

4.2.0 RAM USAGE

4.2.0 STATISTICS

What is the expected behavior

(type here)

Steps to reproduce

(type here)

Extra info(if any)

(type here)

[ghost]

Cache settings were set to auto in 4.2.2. Maybe that could’ve caused this issue. Try setting it manually.

[FranciscoPombal]

Cache settings were set to auto in 4.2.2. Maybe that could’ve caused this issue. Try setting it manually.

Assuming all of the 2 GiB extra usage is cache, you'd have to have 80 GiB or more of system memory for libtorrent to allocate that much when the cache setting is set to auto. If you do have 80 GiB or more of system memory, then everything is working fine and the auto setting is just not suitable for your use case, in which case you should manually set it to some value that suits you. Otherwise, there is a bug in libtorrent (again, assuming all extra 2 GiB memory usage is cache).

[xavier2k6]

seems ok here.... official 4.2.2. -> disk cache (auto/default) (windows 10 x64/32gb RAM)

3 large torrents downloading.....

@p43b1 can you post a screenshot of task manager > performance -> memory.

[FranciscoPombal]

To really get to the bottom of this, and figure out if this is a problem with qBIttorrent or the system, it is necessary to use a profiler. I don't know how it would be on Windows, but it has to be something similar to the (callgrind+kcachegrind, massif) combo on Linux. @xavier2k6 If you know how to do so on Windows, tell @p43b1 how to do it.

[xavier2k6]

@FranciscoPombal I'll have to look into that kind of thing....I'm just wondering if "compressed memory" on/off makes a difference, I have it enabled....hence why I asked for task manager screenshot.......currently can't go fiddling/testing with settings/test machines.

EDIT: Also @p43b1 do you have "Enable OS cache" checked or unchecked in the advanced settings?

[FranciscoPombal]

@xavier2k6 These were the results I found consistently when googling: https://github.com/milostosic/MTuner https://github.com/dynamorio/drmemory https://docs.microsoft.com/en-us/sysinternals/downloads/vmmap https://hacksoflife.blogspot.com/2009/06/heap-debugging-memoryresource-leak-with.html

The Qt wiki also has a wiki page that names the first 2 among many others: https://wiki.qt.io/Profiling_and_Memory_Checking_Tools

[xavier2k6]

@FranciscoPombal I have debugdiag attached 24/7 with full page heaps enabled......yet mem seems ok?!

I know there's a memory leak alright in Qt which will be fixed in Qt 5.14.2

[telans]

I think I may be having the same issue. Running on Linux with qbittorrent-nox 4.2.2 (libtorrent 1.2.5). Around 60 torrents with 8 active.

Been running for ~4 hours with just over 2 GiB usage. I do have 512MiB disk cache set, but the total usage still seems excessive.

Is this an issue or expected behaviour?

UPDATE: Just ran into OOM, restarted qbittorrent-nox and it's at 100MiB usage

[xavier2k6]

@FranciscoPombal did you get any further debug/info out of #11879?

[p43b1]

seems ok here.... official 4.2.2. -> disk cache (auto/default) (windows 10 x64/32gb RAM)

3 large torrents downloading.....

@p43b1 can you post a screenshot of task manager > performance -> memory.

All three taken at the very same moment

Edit:

[FranciscoPombal]

@xavier2k6 no, since I had the problems with the alert patches mentioned near the end, I did not give it another go. Perhaps I should try again.

@p43b1 Can MTuner show symbol names? Without them it is difficult to see where exactly the most memory is being allocated. Perhaps you need to point it at qBittorrent's .pdb file? Also can it export data in a massif-compatible format (or any format at all)? If so, post the export here so that others can analyze.

EDIT: I see at least the stack trace in the bottom right seems to have symbol names, but the useful bits are on the top of the stack (which would be in the bottom of the list, not visible in the screenshot). Please export a snapshot of the data when you are experiencing the increased memory usage so that others can attempt to analyze.

If this leak/increased usage is also related to the crypto library functions, this can be closed as a duplicate of the other issue and we can regroup and refocus our efforts over there.

[FranciscoPombal]

@telans Since you are on Linux, can you provide massif output from a run where you observe excessive memory usage? Read through https://github.com/qbittorrent/qBittorrent/issues/11879 if you don't know where to start.

[telans]

@telans Since you are on Linux, can you provide massif output from a run where you observe excessive memory usage? Read through #11879 if you don't know where to start.

Should I build with the suggested flags?

[xavier2k6]

@FranciscoPombal quick observation & thinking out loud..... @p43b1 has a set/custom disk cache 128MiB where as I have auto -> which follows libtorrents limits/algorithm (for amount of ram in the system)

I only presume that when a set/custom disk cache is used these limits are no longer adhered to......but is the set/custom disk cache figure restricted to just that amount & if it is....maybe the restrictor could be the issue/leaker.....

[FranciscoPombal]

@telans

Should I build with the suggested flags?

You should compile and build normally (assuming you are on Ubuntu, here is the guide: https://github.com/qbittorrent/qBittorrent/wiki/Compiling-qBittorrent-on-Debian-and-Ubuntu) and then run at least massif (example in the folder where the qbittorrent executable is built): valgrind --tool=massif --verbose --massif-out-file=massif_output.mass qbittorrent

This comment shows other examples for memcheck and callgrind as well: https://github.com/qbittorrent/qBittorrent/issues/11879#issuecomment-578421275. But for this case, massif is the most important.

[FranciscoPombal]

@FranciscoPombal quick observation & thinking out loud..... @p43b1 has a set/custom disk cache 128MiB where as I have auto -> which follows libtorrents limits/algorithm (for amount of ram in the system)

I only presume that when a set/custom disk cache is used these limits are no longer adhered to......but is the set/custom disk cache figure restricted to just that amount & if it is....maybe the restrictor could be the issue/leaker.....

@p43b1 you can try auto, but I seriously doubt that choosing a specific value is causing a bug. As far as I know, that libtorrent code hasn't changed in a while. As an additional note, the amount of RAM used when auto is selected is chosen according to the following logic: https://github.com/arvidn/libtorrent/blob/9ac4e6eed88c1ea1e6cdb6865889320164ad0b85/src/disk_buffer_pool.cpp#L298

[farnoy]

I managed to capture it, summary:

--------------------------------------------------------------------------------
Command:            qbittorrent
Massif arguments:   --massif-out-file=/tmp/massif_output.mass
ms_print arguments: massif_output.mass
--------------------------------------------------------------------------------

    GB
2.859^                 #
     |                 #
     |                 #
     |                 #
     |                 #
     |                 #
     |                 #
     |                 #
     |                 #
     |                 #
     |                 #
     |                 #
     |                 #
     |                 #
     |                 #
     |                 #
     |                 #
     |                 #                                        @@
     |             ::::#:::@@::::::::::::::::::::::::::::::@:@@:@ :::::::::@@:
     | @ :: ::::::::: :#: :@ :: :: : ::: : : :: :::: ::: : @:@ :@ : :: :: :@@:
   0 +----------------------------------------------------------------------->Gi
     0                                                                   823.0

Number of snapshots: 76
 Detailed snapshots: [1, 13 (peak), 16, 39, 41, 43, 57, 67]

Some details:

--------------------------------------------------------------------------------
  n        time(i)         total(B)   useful-heap(B) extra-heap(B)    stacks(B)
--------------------------------------------------------------------------------
 58 856,650,432,519      424,960,408      416,647,537     8,312,871            0
 59 858,239,338,260      392,988,768      384,705,079     8,283,689            0
 60 859,832,688,763      419,595,648      411,267,061     8,328,587            0
 61 861,424,245,926      407,544,312      399,262,252     8,282,060            0
 62 863,013,195,999      446,006,032      437,654,179     8,351,853            0
 63 864,624,826,466      375,025,576      366,748,075     8,277,501            0
 64 866,213,876,908      412,153,368      403,844,962     8,308,406            0
 65 867,802,873,810      375,863,728      367,613,940     8,249,788            0
 66 869,391,757,318      448,007,912      439,672,697     8,335,215            0
 67 870,996,467,026      419,839,816      411,512,548     8,327,268            0
98.02% (411,512,548B) (heap allocation functions) malloc/new/new[], --alloc-fns, etc.
->33.31% (139,868,696B) 0x4C756E9: ??? (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
| ->33.24% (139,567,624B) 0x4D7FE79: ??? (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
| | ->33.24% (139,558,056B) 0x4D3DC4E: ??? (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
| | | ->33.11% (139,020,104B) 0x4D4BC14: ??? (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
| | | | ->33.11% (139,020,104B) 0x4D60B23: ??? (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
| | | |   ->32.38% (135,925,280B) 0x4C5F58C: ??? (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
| | | |   | ->32.38% (135,925,280B) 0x4D8F675: ??? (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
| | | |   |   ->32.38% (135,925,280B) 0x65FCB23: execute_native_thread_routine (thread.cc:80)
| | | |   |     ->32.38% (135,925,280B) 0x4FF846E: start_thread (in /usr/lib/libpthread-2.31.so)
| | | |   |       ->32.38% (135,925,280B) 0x69773D2: clone (in /usr/lib/libc-2.31.so)
| | | |   |
| | | |   ->00.74% (3,094,824B) in 1+ places, all below ms_print's threshold (01.00%)
| | | |
| | | ->00.13% (537,952B) in 1+ places, all below ms_print's threshold (01.00%)
| | |
| | ->00.00% (9,568B) in 1+ places, all below ms_print's threshold (01.00%)
| |
| ->00.07% (301,072B) in 1+ places, all below ms_print's threshold (01.00%)
|
->13.73% (57,646,962B) 0x4E93921: libtorrent::torrent_info::parse_info_section(libtorrent::bdecode_node const&, boost::system::error_code&, int) (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
| ->13.73% (57,646,962B) 0x4E96C11: libtorrent::torrent_info::parse_torrent_file(libtorrent::bdecode_node const&, boost::system::error_code&, int) (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
|   ->13.73% (57,646,962B) 0x4E9AEC3: libtorrent::torrent_info::torrent_info(libtorrent::bdecode_node const&, boost::system::error_code&) (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
|     ->13.73% (57,646,962B) 0x27803C: BitTorrent::TorrentInfo::load(QByteArray const&, QString*) (in /usr/bin/qbittorrent)
|       ->13.73% (57,646,962B) 0x27AA9F: BitTorrent::TorrentInfo::loadFromFile(QString const&, QString*) (in /usr/bin/qbittorrent)
|         ->13.68% (57,423,929B) 0x258EF8: ??? (in /usr/bin/qbittorrent)
|         | ->13.68% (57,423,929B) 0x259378: BitTorrent::Session::startUpTorrents() (in /usr/bin/qbittorrent)
|         |   ->13.68% (57,423,929B) 0x223CA9: Application::exec(QStringList const&) (in /usr/bin/qbittorrent)
|         |     ->13.68% (57,423,929B) 0x21B1C7: main (in /usr/bin/qbittorrent)
|         |
|         ->00.05% (223,033B) in 1+ places, all below ms_print's threshold (01.00%)
|

Looks like thread creation might be leaking things? I killed it after reaching almost 3Gi RSS, while downloading a big torrent.

I'm not sure how to read it, but it seems to point the finger at spawning threads? But I strace-d it and it doesn't seem to clone any while downloading intensively :man_shrugging:

[FranciscoPombal]

@farnoy do you mind uploading the full output file, in case you saved it? You can simply attach it to your post.

[FranciscoPombal]

Also, if possible, compile and use libtorrent with debug symbols so that we can see the stacktrace for the libtorrent portion.

98.02% (411,512,548B) (heap allocation functions) malloc/new/new[], --alloc-fns, etc.
->33.31% (139,868,696B) 0x4C756E9: ??? (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
| ->33.24% (139,567,624B) 0x4D7FE79: ??? (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
| | ->33.24% (139,558,056B) 0x4D3DC4E: ??? (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
| | | ->33.11% (139,020,104B) 0x4D4BC14: ??? (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
| | | | ->33.11% (139,020,104B) 0x4D60B23: ??? (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
| | | |   ->32.38% (135,925,280B) 0x4C5F58C: ??? (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
| | | |   | ->32.38% (135,925,280B) 0x4D8F675: ??? (in /usr/lib/libtorrent-rasterbar.so.10.0.0)

[farnoy]

I will recompile libtorrent with debugging, for now, this is the whole file. massif_output.zip

[farnoy]

Ok, I'm building with autotools and a simple configure --enable-debug ... produces a build that: 1) is too slow to allocate anything substantial while downloading 2) crashes when closing qBittorrent with:

version: 1.2.5.0-9469913cb

file: '../../libtorrent-rasterbar-1.2.5/src/torrent.cpp'
line: 7875
function: check_invariant
expression: want_peers_finished() == m_links[aux::session_interface::torrent_want_peers_finished].in_list()

I'll try to compile a version with debug symbols, but with full optimizations and no assertions.

[p43b1]

Ok

1) Disk cache set to auto

2) Two screenshots from MTTuner (I think it doesn't record "live" but it makes just a snapshot)

[farnoy]

@FranciscoPombal Here's one with debug symbols massif_output.zip

I'm not sure this is correct, I killed it around 700Mi of RSS, but massif's summary is showing 255Mi peak memory used?

[mozo78]

No problems on Linux with 2648 runnung tasks: https://i.imgur.com/S5b5G9g.png

[FranciscoPombal]

@farnoy thanks. If you could generate another one with an even bigger peak and a larger leak, that would be even better.

@arvidn can you take a look at this please? Even of that smaller one, is it normal for the receive buffer to be so big? And also parse_info_section?

[FranciscoPombal]

@p43b1 can you please compile with debug symbols/configure MTTuner to use debug symbols, and post the exported data so that others can analyze freely in more detail? I realize this is not the easiest thing to do on Windows, it's fine if you don't do it.

But just as an example, with @farnoy's output posted above, I can open it and look at it in detail in massif-visualizer:

[telans]

@FranciscoPombal Running with valgrind left the memory as what I would expect, around 750MiB usage.

There isn't a specific action I do to make the memory jump, it just seems to leak over time. A few hours with valgrind uses much less memory than an hour without valgrind.

I'll leave it overnight to really test it. (or is it expected that it should take longer?)

[FranciscoPombal]

@telans I would not say leaving it running all night is necessary. A couple of hours of usage OR until it reaches a couple of GiBs of memory usage or more, whichever comes first, should be enough to gather some interesting data.

[telans]

I've managed to trigger the 'leak' (or whatever it is) somehow twice more without valgrind, but for some reason it's just not occuring with valgrind.

Without valgrind the usage slowly climbs over 1.5GiB, but with it always remains steady at 730MiB (500 disk buffer, 230 for the rest). Are there any other memory analyzing tools I should try?

[p43b1]

I hope I could do something useful...

1) For reproducibility

I used this software https://docs.microsoft.com/en-us/sysinternals/downloads/vmmap

2) This is the screenshot of qbittorrent's process

3) This is the file. It's the same file, one in .mmp, one in .csv file format.

qbittorrent_csv_file_format.zip qbittorrent_mmp_file_format.zip

[farnoy]

I ran it overnight, but couldn't reproduce the long term leak on libtorrent compiled with -g -O2 and no assertions.

EDIT: I was testing with valgrind --tool=massif, so maybe it is to blame for preventing leakage.

[joy4eg]

4.2.2, fedora 32. 230+ torrents.

15 GB ...

[joy4eg]

Related issue: https://github.com/qbittorrent/qBittorrent/issues/11581

[telans]

4.2.2, fedora 32. 230+ torrents.

Are you able to trigger the leak with massif?

valgrind --tool=massif --verbose --massif-out-file=massif_output.mass qbittorrent

[arvidn]

Is 15 GB a lot a compared to your expectation or compared to your cache size setting? If the former, what is your cache size setting? If it's "auto", given your system, what would a reasonable automatic cache size be? (currently it's essentially a log function of the total amount of RAM)

In any other case, there could be a bug. However, probably the second most memory consuming part are socket buffers. If you have a lot of peers, it's possible for those to get quite big too. Both of these numbers are actually available in the session stats.

[arvidn]

also, if anyone is of the opinion that qBT shouldn't have a cache size setting, but it should "just work", I agree. The next major version of libtorrent will defer disk caching to the operating system. But that's still some time out.

[joy4eg]

@arvidn Yeah, I have "auto". But the previous version took much less memory - https://github.com/qbittorrent/qBittorrent/issues/11581#issuecomment-566914529

I'll try to dig in with valgrind as @telans proposed.

[joy4eg]

So it's pretty reproducible on my machine.

That screen is from massif_output2.mass: google drive.

For some reason all roads lead to on_tracker_announce()

[farnoy]

I was able to capture a profile with debug info of libtorrent. I have disk cache set to disabled (0), this is the interesting snippet:

--------------------------------------------------------------------------------
  n        time(i)         total(B)   useful-heap(B) extra-heap(B)    stacks(B)
--------------------------------------------------------------------------------
 39 156,113,888,304    2,193,275,384    2,176,662,491    16,612,893            0
 40 160,544,089,185    1,338,315,976    1,327,048,580    11,267,396            0
 41 162,768,723,780      163,928,720      158,563,786     5,364,934            0
 42 167,210,833,411    1,369,959,664    1,357,736,612    12,223,052            0
 43 169,567,102,787    3,774,431,808    3,749,046,029    25,385,779            0
99.33% (3,749,046,029B) (heap allocation functions) malloc/new/new[], --alloc-fns, etc.
->20.27% (765,255,680B) 0x495604F: ??? (in /usr/lib/libcrypto.so.1.1)
| ->20.27% (765,255,680B) 0x4954115: BIO_ctrl (in /usr/lib/libcrypto.so.1.1)
|   ->20.27% (765,255,680B) 0x4956170: BIO_new_bio_pair (in /usr/lib/libcrypto.so.1.1)
|     ->20.27% (765,255,680B) 0x4E0D566: boost::asio::ssl::detail::stream_core::stream_core<boost::asio::executor>(ssl_ctx_st*, boost::asio::executor const&) (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
|       ->20.27% (765,255,680B) 0x4E07E61: libtorrent::aux::socket_type::construct(int, void*) (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
|         ->20.27% (765,255,680B) 0x4D0D4C0: libtorrent::aux::instantiate_connection(boost::asio::io_context&, libtorrent::aux::proxy_settings const&, libtorrent::aux::socket_type&, void*, libtorrent::utp_socket_manager*, bool, bool) (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
|           ->20.27% (765,255,680B) 0x4CBA85B: libtorrent::http_connection::start(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, int, std::chrono::duration<long, std::ratio<1l, 1000000000l> >, int, libtorrent::aux::proxy_settings const*, bool, int, boost::optional<boost::asio::ip::address> const&, libtorrent::flags::bitfield_flag<unsigned char, libtorrent::resolver_flag_tag, void>, libtorrent::i2p_connection*) (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
|             ->20.27% (765,255,680B) 0x4CBBC8D: libtorrent::http_connection::get(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::chrono::duration<long, std::ratio<1l, 1000000000l> >, int, libtorrent::aux::proxy_settings const*, int, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, boost::optional<boost::asio::ip::address> const&, libtorrent::flags::bitfield_flag<unsigned char, libtorrent::resolver_flag_tag, void>, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, libtorrent::i2p_connection*) (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
|               ->20.27% (765,255,680B) 0x4CFF4E3: libtorrent::http_tracker_connection::start() (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
|                 ->20.27% (765,255,680B) 0x4EB9DF0: libtorrent::tracker_manager::queue_request(boost::asio::io_context&, libtorrent::tracker_request&&, std::weak_ptr<libtorrent::request_callback>) (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
|                   ->20.27% (765,255,680B) 0x4DD5B12: libtorrent::aux::session_impl::queue_tracker_request(libtorrent::tracker_request&&, std::weak_ptr<libtorrent::request_callback>) (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
|                     ->20.27% (765,255,680B) 0x4E57B3B: libtorrent::torrent::announce_with_tracker(unsigned char) (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
|                       ->20.27% (765,255,680B) 0x4E59476: libtorrent::torrent::on_tracker_announce(boost::system::error_code const&) (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
|                       | ->20.27% (765,255,680B) 0x4E84DF6: void libtorrent::torrent::wrap<void (libtorrent::torrent::*)(boost::system::error_code const&), boost::system::error_code const&>(void (libtorrent::torrent::*)(boost::system::error_code const&), boost::system::error_code const&) (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
|                       |   ->20.27% (765,255,680B) 0x4E72BF7: boost::asio::detail::wait_handler<libtorrent::torrent::update_tracker_timer(std::chrono::time_point<std::chrono::_V2::system_clock, std::chrono::duration<int, std::ratio<1l, 1l> > >)::{lambda(boost::system::error_code const&)
|                       |     ->20.27% (765,255,680B) 0x4C6427C: boost::asio::detail::scheduler::run(boost::system::error_code&) (in /usr/lib/libtorrent-rasterbar.so.10.0.0)
|                       |       ->20.27% (765,255,680B) 0x4D9D125: std::thread::_State_impl<std::thread::_Invoker<std::tuple<libtorrent::session::start(libtorrent::session_params&&, boost::asio::io_context*)::{lambda()
|                       |         ->20.27% (765,255,680B) 0x6613B23: execute_native_thread_routine (thread.cc:80)
|                       |           ->20.27% (765,255,680B) 0x501146E: start_thread (in /usr/lib/libpthread-2.31.so)
|                       |             ->20.27% (765,255,680B) 0x698E3D2: clone (in /usr/lib/libc-2.31.so)
|                       |
|                       ->00.00% (0B) in 1+ places, all below ms_print's threshold (01.00%)

massif_output_debug.zip

[FranciscoPombal]

@arvidn I re-opened a result from an older thread (https://github.com/qbittorrent/qBittorrent/issues/11879#issuecomment-581017871) and the results are similar to what is observed now (keep in mind the libtorrent version used here is a bit older):

Comparing to the massif outputs in this thread, looks like this is still the HTTPS tracker announce issue from before.

[FranciscoPombal]

@p43b1 I don't think those files are very useful, at least the .csv did not contain any stacktrace info. I'm sorry I can't guide you further, I don't know how to produce similar reports on Windows.

[eigerzoom]

What I dont understand is when rolling back to previous versions of qb client, before the problem existed, the issue remains. That simply doesn't add up. Can someone take a stab at explaining this?

[telans]

What I dont understand is when rolling back to previous versions of qb client, before the problem existed, the issue remains. That simply doesn't add up. Can someone take a stab at explaining this?

I assume it's because you still have the latest libtorrent installed

[farnoy]

So what's the consensus so far? Is it fair to say that the issue is in libtorrent and any changes qBittorrent has done recently have not introduced it, but perhaps made it trigger more frequently (to unleash waves of people reporting this issue here)?

[arvidn]

my theory is that the SSL async_shutdown call never completes. The SSL support in libtorrent was slapped on a little bit as an afterthought, and normally, closing a socket is not an operation that takes time or stalls. But in order to (correctly) close an SSL stream, you need to do a shutdown handshake with the other end. If the tracker doesn't bother doing clean shutdowns (which really is a security issue) or if the network is flaky and the connection is dropped, libtorrent can get stuck indefinitely waiting for the handshake.

It could be related to this change: https://github.com/arvidn/libtorrent/pull/2797

Either way, I hope to have time, at some point, to rewrite the HTTP trackers to be simpler and more robust (based on boost.beast), and fix this issue better. I think there really need to be a time-out for this.

[farnoy]

@arvidn Out of curiosity, and sorry if this is off topic, but are you sure it's a security issue to disconnect the socket without cleanly ending the TLS session? I followed the links you posted and the example given is one where the attacker blocks a user from logging out and ending their (web) session. Doesn't seem relevant in this case.

[arvidn]

I can't think of a specific attack, other than denial of service by blocking packets. But I also don't think it's safe to assume there aren't any.

anyway, could someone please try https://github.com/arvidn/libtorrent/pull/4494 ?

[joy4eg]

@arvidn

assertion failed. Please file a bugreport at https://github.com/arvidn/libtorrent/issues
Please include the following information:

version: 1.2.5.0-9469913cb

file: '../../src/socket_type.cpp'
line: 338
function: close
expression: <unconditional>

stack:
1: libtorrent::assert_fail(char const*, int, char const*, char const*, char const*, int)
2: 
3: 
4: boost::asio::detail::scheduler::do_run_one(boost::asio::detail::conditionally_enabled_mutex::scoped_lock&, boost::asio::detail::scheduler_thread_info&, boost::system::error_code const&)
5: boost::asio::detail::scheduler::run(boost::system::error_code&)
6: 
7: 
8: 
9: clone

Thread 5 "qbittorrent" received signal SIGABRT, Aborted
[Switching to Thread 0x7fffe41e1700 (LWP 380573)]
0x00007ffff75e0915 in raise () from /usr/lib64/libpthread.so.0
(gdb) bt
#0  0x00007ffff75e0915 in raise () from /usr/lib64/libpthread.so.0
#1  0x00007ffff77c82ed in libtorrent::assert_fail (expr=0x7ffff7af20ea "<unconditional>", line=338, file=0x7ffff7b1dff4 "../../src/socket_type.cpp", function=0x7ffff7b058ff "close", value=<optimized out>, kind=0)
    at ../../src/assert.cpp:380
#2  0x00007ffff7848f74 in operator() (__closure=0x7fffe41df878) at /usr/include/c++/10/bits/shared_ptr_base.h:1321
#3  boost::asio::ssl::detail::shutdown_op::call_handler<libtorrent::http_connection::close(bool)::<lambda(const error_code&)> > (ec=..., handler=..., this=0x7fffe41df850) at /usr/include/boost/asio/ssl/detail/shutdown_op.hpp:45
#4  boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> >::operator()(boost::system::error_code, std::size_t, int) (this=0x7fffe41df840, ec=..., bytes_transferred=0, start=<optimized out>) at /usr/include/boost/asio/ssl/detail/io.hpp:262
#5  0x00007ffff7849cd4 in boost::asio::detail::binder2<boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> >, boost::system::error_code, long unsigned int>::operator() (this=0x7fffe41df840) at /usr/include/boost/asio/detail/bind_handler.hpp:162
#6  boost::asio::asio_handler_invoke<boost::asio::detail::binder2<boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> >, boost::system::error_code, long unsigned int> > (function=...) at /usr/include/boost/asio/handler_invoke_hook.hpp:69
#7  boost_asio_handler_invoke_helpers::invoke<boost::asio::detail::binder2<boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> >, boost::system::error_code, long unsigned int>, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> > (context=..., function=...)
    at /usr/include/boost/asio/detail/handler_invoke_helpers.hpp:37
#8  boost::asio::ssl::detail::asio_handler_invoke<boost::asio::detail::binder2<boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> >, boost::system::error_code, long unsigned int>, boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> > (this_handler=0x7fffe41df840, function=...) at /usr/include/boost/asio/ssl/detail/io.hpp:316
#9  boost_asio_handler_invoke_helpers::invoke<boost::asio::detail::binder2<boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> >, boost::system::error_code, long unsigned int>, boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> > > (context=..., function=...) at /usr/include/boost/asio/detail/handler_invoke_helpers.hpp:37
#10 boost::asio::detail::handler_work<boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> >, boost::asio::system_executor>::complete<boost::asio::detail::binder2<boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> >, boost::system::error_code, long unsigned int> > (handler=..., function=..., this=<synthetic pointer>) at /usr/include/boost/asio/detail/handler_work.hpp:82
#11 boost::asio::detail::reactive_socket_recv_op<boost::asio::mutable_buffers_1, boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> > >::do_complete(void *, boost::asio::detail::operation *, const boost::system::error_code &, std::size_t) (owner=0xe168d0, base=0x7fff507c5180)
    at /usr/include/boost/asio/detail/reactive_socket_recv_op.hpp:122
#12 0x00007ffff78074c5 in boost::asio::detail::scheduler_operation::complete (bytes_transferred=<optimized out>, ec=..., owner=0xe168d0, this=0x7fff507c5180) at /usr/include/boost/asio/detail/scheduler_operation.hpp:40
#13 boost::asio::detail::scheduler::do_run_one (this=this@entry=0xe168d0, lock=..., this_thread=..., ec=...) at /usr/include/boost/asio/detail/impl/scheduler.ipp:401
#14 0x00007ffff78532c1 in boost::asio::detail::scheduler::run (this=0xe168d0, ec=...) at /usr/include/boost/asio/detail/impl/scheduler.ipp:154
#15 0x00007ffff792cb58 in std::thread::_State_impl<std::thread::_Invoker<std::tuple<libtorrent::session::start(libtorrent::session_params&&, boost::asio::io_context*)::{lambda()#1}> > >::_M_run() ()
    at /usr/include/boost/asio/impl/io_context.ipp:62
#16 0x00007ffff6102a94 in execute_native_thread_routine () from /usr/lib64/libstdc++.so.6
#17 0x00007ffff75d5432 in start_thread () from /usr/lib64/libpthread.so.0
#18 0x00007ffff5e009d3 in clone () from /usr/lib64/libc.so.6

I have rb_torrent from fedora 32 + your PR as a patch (debug enabled). And also crashing without debug flag:

#0  operator() (__closure=0x7fffe429f878) at ../../src/http_connection.cpp:474
#1  boost::asio::ssl::detail::shutdown_op::call_handler<libtorrent::http_connection::close(bool)::<lambda(const error_code&)> > (ec=..., handler=..., this=0x7fffe429f850) at /usr/include/boost/asio/ssl/detail/shutdown_op.hpp:45
#2  boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> >::operator()(boost::system::error_code, std::size_t, int) (this=0x7fffe429f840, ec=..., bytes_transferred=0, start=<optimized out>) at /usr/include/boost/asio/ssl/detail/io.hpp:262
#3  0x00007ffff78dac74 in boost::asio::detail::binder2<boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> >, boost::system::error_code, long unsigned int>::operator() (this=0x7fffe429f840) at /usr/include/boost/asio/detail/bind_handler.hpp:162
#4  boost::asio::asio_handler_invoke<boost::asio::detail::binder2<boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> >, boost::system::error_code, long unsigned int> > (function=...) at /usr/include/boost/asio/handler_invoke_hook.hpp:69
#5  boost_asio_handler_invoke_helpers::invoke<boost::asio::detail::binder2<boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> >, boost::system::error_code, long unsigned int>, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> > (context=..., function=...)
    at /usr/include/boost/asio/detail/handler_invoke_helpers.hpp:37
#6  boost::asio::ssl::detail::asio_handler_invoke<boost::asio::detail::binder2<boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> >, boost::system::error_code, long unsigned int>, boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> > (this_handler=0x7fffe429f840, function=...) at /usr/include/boost/asio/ssl/detail/io.hpp:316
#7  boost_asio_handler_invoke_helpers::invoke<boost::asio::detail::binder2<boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> >, boost::system::error_code, long unsigned int>, boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> > > (context=..., function=...) at /usr/include/boost/asio/detail/handler_invoke_helpers.hpp:37
#8  boost::asio::detail::handler_work<boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> >, boost::asio::system_executor>::complete<boost::asio::detail::binder2<boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> >, boost::system::error_code, long unsigned int> > (handler=..., function=..., this=<synthetic pointer>) at /usr/include/boost/asio/detail/handler_work.hpp:82
#9  boost::asio::detail::reactive_socket_recv_op<boost::asio::mutable_buffers_1, boost::asio::ssl::detail::io_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::ssl::detail::shutdown_op, libtorrent::http_connection::close(bool)::<lambda(const error_code&)> > >::do_complete(void *, boost::asio::detail::operation *, const boost::system::error_code &, std::size_t) (owner=0xe127a0, base=0x7fff542724a0)
    at /usr/include/boost/asio/detail/reactive_socket_recv_op.hpp:122
#10 0x00007ffff78a4f69 in boost::asio::detail::scheduler_operation::complete (bytes_transferred=<optimized out>, ec=..., owner=0xe127a0, this=0x7fff542724a0) at /usr/include/boost/asio/detail/scheduler_operation.hpp:40
#11 boost::asio::detail::scheduler::do_run_one (this=this@entry=0xe127a0, lock=..., this_thread=..., ec=...) at /usr/include/boost/asio/detail/impl/scheduler.ipp:401
#12 0x00007ffff78e3971 in boost::asio::detail::scheduler::run (this=0xe127a0, ec=...) at /usr/include/boost/asio/detail/impl/scheduler.ipp:154
#13 0x00007ffff798f758 in boost::asio::io_context::run (this=<optimized out>) at /usr/include/boost/asio/impl/io_context.ipp:62
#14 operator() (__closure=<optimized out>) at ../../src/session.cpp:355
#15 std::__invoke_impl<void, libtorrent::session::start(libtorrent::session_params&&, libtorrent::io_service*)::<lambda()> > (__f=...) at /usr/include/c++/10/bits/invoke.h:60
#16 std::__invoke<libtorrent::session::start(libtorrent::session_params&&, libtorrent::io_service*)::<lambda()> > (__fn=...) at /usr/include/c++/10/bits/invoke.h:95
#17 std::thread::_Invoker<std::tuple<libtorrent::session::start(libtorrent::session_params&&, libtorrent::io_service*)::<lambda()> > >::_M_invoke<0> (this=<optimized out>) at /usr/include/c++/10/thread:264
#18 std::thread::_Invoker<std::tuple<libtorrent::session::start(libtorrent::session_params&&, libtorrent::io_service*)::<lambda()> > >::operator() (this=<optimized out>) at /usr/include/c++/10/thread:271
#19 std::thread::_State_impl<std::thread::_Invoker<std::tuple<libtorrent::session::start(libtorrent::session_params&&, libtorrent::io_service*)::<lambda()> > > >::_M_run(void) (this=<optimized out>)
    at /usr/include/c++/10/thread:215
#20 0x00007ffff61c2a94 in execute_native_thread_routine () from /usr/lib64/libstdc++.so.6
#21 0x00007ffff7695432 in start_thread () from /usr/lib64/libpthread.so.0
#22 0x00007ffff5ec09d3 in clone () from /usr/lib64/libc.so.6
(gdb) info locals
e = {val_ = 0, failed_ = false, cat_ = 0xbe8140 <boost::system::detail::cat_holder<void>::system_category_instance>}
self = std::shared_ptr<libtorrent::http_connection> (expired, weak count 0) = {get() = 0x1}
self = <optimized out>
e = <optimized out>

   468          {
   469  #ifdef TORRENT_USE_OPENSSL
   470                  auto self = shared_from_this();
   471                  auto handler = [&](error_code const&) {
   472                          COMPLETE_ASYNC("on_close_socket");
   473                          error_code e;
   474                          self->m_timer.cancel(e);
   475                          self->m_sock.close(e);
   476                  };

[arvidn]

@joy4eg thanks for testing! I force pushed a fix to that PR

[joy4eg]

@arvidn Awesome! I'll leave it running for a while to collect a new massif report.