Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[RFC] Switch and/or align debugging flags (back) to -Og #29796

Draft
wants to merge 2 commits into
base: master
Choose a base branch
from

Conversation

fanquake
Copy link
Member

@fanquake fanquake commented Apr 3, 2024

We currently have two issues in relation to debugging optimisation flags:

I'm not completely sure yet what the right choice is (previously it seems that -Og was unusable with Clang? (note that for Clang it looks like -Og and -O1 are basically equivalent), but we should at least align the two systems to be using the same thing for debugging.

Configure history:
-O0 added in #3833
Switched to -Og in #13005.
Switched back to -O0 #16435

Depends DEBUG=1 mode has used -O1 since inception.

@DrahtBot
Copy link
Contributor

DrahtBot commented Apr 3, 2024

The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

Code Coverage

For detailed information about the code coverage, see the test coverage report.

Reviews

See the guideline for information on the review process.

Type Reviewers
Concept ACK hebasto, emc99, theuni

If your review is incorrectly listed, please react with 👎 to this comment and the bot will ignore it on the next update.

@hebasto
Copy link
Member

hebasto commented Apr 3, 2024

  • A depends build with DEBUG=1 and using ./configure --enable-debug do not align, which is inconsistent/confusing.

Concept ACK on fixing that.

@emc99
Copy link

emc99 commented Apr 3, 2024

Concept ACK

@theuni
Copy link
Member

theuni commented Apr 3, 2024

Concept ACK.

I think msan is a good proxy for what we want enabled. From its docs:

To get a reasonable performance add -O1 or higher. To get meaningful stack traces in error messages add -fno-omit-frame-pointer. To get perfect stack traces you may need to disable inlining (just use -O1) and tail call elimination (-fno-optimize-sibling-calls).

From gcc's docs on -Og

-Og should be the optimization level of choice for the standard edit-compile-debug cycle, offering a reasonable level of optimization while maintaining fast compilation and a good debugging experience. It is a better choice than -O0 for producing debuggable code because some compiler passes that collect debug information are disabled at -O0. Like -O0, -Og completely disables a number of optimization passes so that individual options controlling them have no effect. Otherwise -Og enables all -O1 optimization flags except for those that may interfere with debugging

From what I can tell, -O1 (and thus -Og) will disable the frame pointer. So we may also want to add -fno-omit-frame-pointer as recommended by llvm, but IMO we can wait and see if it turns out to be necessary for anyone first.

@achow101
Copy link
Member

achow101 commented Apr 3, 2024

While this does resolve the compile issue I was having, it does seem to change how gdb is able to debug things, possibly in a meaningful way? This is just an example of a difference that I noticed while stepping through CWallet::Create with and without this PR:

On master:

Thread 4 "b-httpworker.0" hit Breakpoint 1, wallet::CWallet::Create (context=..., name="funds", database=std::unique_ptr<wallet::WalletDatabase> = {...}, 
    wallet_creation_flags=0, error=..., warnings=std::vector of length 0, capacity 0) at wallet/wallet.cpp:2948
2948	{
(gdb) n
2949	   interfaces::Chain* chain = context.chain;
(gdb) 
2950	   ArgsManager& args = *Assert(context.args);
(gdb) 
2024-04-03T18:24:24.238066Z [addcon] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_nodes_mutex, net.cpp:2768 started
2024-04-03T18:24:24.238169Z [addcon] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_nodes_mutex, net.cpp:2768 completed (1μs)
2024-04-03T18:24:24.238246Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_nodes_mutex, net.cpp:1860 started
2024-04-03T18:24:24.238343Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_nodes_mutex, net.cpp:1860 completed (3μs)
2951	   const std::string& walletFile = database->Filename();
(gdb) 
2953	   const auto start{SteadyClock::now()};
(gdb) 
2024-04-03T18:24:25.288339Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_nodes_mutex, net.cpp:1860 started
2024-04-03T18:24:25.288437Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_nodes_mutex, net.cpp:1860 completed (3μs)
2956	   std::shared_ptr<CWallet> walletInstance(new CWallet(chain, name, std::move(database)), ReleaseWallet);
(gdb) 
2024-04-03T18:24:25.789076Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_nodes_mutex, net.cpp:1932 started
2024-04-03T18:24:25.789145Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_nodes_mutex, net.cpp:1932 completed (2μs)
2957	   walletInstance->m_keypool_size = std::max(args.GetIntArg("-keypool", DEFAULT_KEYPOOL_SIZE), int64_t{1});
(gdb) 
2958	   walletInstance->m_notify_tx_changed_script = args.GetArg("-walletnotify", "");
(gdb) 
2961	   bool rescan_required = false;
(gdb) 
2962	   DBErrors nLoadWalletRet = walletInstance->LoadWallet();
(gdb) 
2024-04-03T18:24:27.971293Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention connman.m_nodes_mutex, ./net.h:1622 started
2024-04-03T18:24:27.971368Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention connman.m_nodes_mutex, ./net.h:1622 completed (2μs)
2024-04-03T18:24:27.972260Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Wallet file version = 10500, last client version = 279900
2024-04-03T18:24:28.845346Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Descriptors: 8, Descriptor Keys: 1 plaintext, 0 encrypted, 1 total.
2024-04-03T18:24:29.556576Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Setting spkMan to active: id = 7bb07d3df110f36af92db5568fb8d4cc1381dd0a6d24b17182ed87cad6ab1d33, type = legacy, internal = false
2024-04-03T18:24:29.556711Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Setting spkMan to active: id = 5cb8f1604559d7b3612008ed3307ca1e21328301d1117b3acdd8b22d5b277219, type = p2sh-segwit, internal = false
2024-04-03T18:24:29.556751Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Setting spkMan to active: id = 68a4834fa805e997434b5c4f2f31625be6f3c5aebae0757293c4215675614a1b, type = bech32, internal = false
2024-04-03T18:24:29.556788Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Setting spkMan to active: id = 19d3e9f0d167b24e3c5330462a0c6cbc3d6e4e06e469967a395835102c0aea4a, type = bech32m, internal = false
2024-04-03T18:24:29.556851Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Setting spkMan to active: id = 09212e585c214fb06d197863920ed50181b984dc6bace73a865ff06a84ec3e61, type = legacy, internal = true
2024-04-03T18:24:29.556892Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Setting spkMan to active: id = 05db3056830116eafc425f192ee58033d44772bbf3bdd62ab50e8d014ecab772, type = p2sh-segwit, internal = true
2024-04-03T18:24:29.556927Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Setting spkMan to active: id = 2fe605d1acd8e46f55fbb47c8162545449df0ab59839219a7541b770a948fa3c, type = bech32, internal = true
2024-04-03T18:24:29.556961Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Setting spkMan to active: id = 115308b94096b7f96245e3ed280290ac5c627c5d666abf5249e4a16bcd5ac79e, type = bech32m, internal = true
2963	   if (nLoadWalletRet != DBErrors::LOAD_OK) {
(gdb) 
3006	   const bool fFirstRun = walletInstance->m_spk_managers.empty() &&
(gdb) 
2024-04-03T18:24:31.018609Z [msghand] [logging/timer.h:58] [Log] [lock] Enter: lock contention connman.m_nodes_mutex, ./net.h:1622 started
2024-04-03T18:24:31.018740Z [msghand] [logging/timer.h:58] [Log] [lock] Enter: lock contention connman.m_nodes_mutex, ./net.h:1622 completed (5μs)
3007	                    !walletInstance->IsWalletFlagSet(WALLET_FLAG_DISABLE_PRIVATE_KEYS) &&

This PR:

Thread 4 "b-httpworker.0" hit Breakpoint 1, wallet::CWallet::Create (context=..., name="funds", database=std::unique_ptr<wallet::WalletDatabase> = {...}, 
    wallet_creation_flags=0, error=..., warnings=std::vector of length 0, capacity 0) at wallet/wallet.cpp:2948
2948	{
(gdb) n
2949	   interfaces::Chain* chain = context.chain;
(gdb) 
2024-04-03T18:21:31.566625Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_nodes_mutex, net.cpp:1860 started
2024-04-03T18:21:31.566715Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_nodes_mutex, net.cpp:1860 completed (1μs)
2950	   ArgsManager& args = *Assert(context.args);
(gdb) 
2024-04-03T18:21:33.071865Z [msghand] [logging/timer.h:58] [Log] [lock] Enter: lock contention connman.m_nodes_mutex, ./net.h:1622 started
2024-04-03T18:21:33.071947Z [msghand] [logging/timer.h:58] [Log] [lock] Enter: lock contention connman.m_nodes_mutex, ./net.h:1622 completed (1μs)
2024-04-03T18:21:33.071995Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_nodes_mutex, net.cpp:1932 started
2024-04-03T18:21:33.072075Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_nodes_mutex, net.cpp:1932 completed (1μs)
2951	   const std::string& walletFile = database->Filename();
(gdb) n
2024-04-03T18:21:47.648919Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_nodes_mutex, net.cpp:1932 started
2024-04-03T18:21:47.649023Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_nodes_mutex, net.cpp:1932 completed (1μs)
2953	   const auto start{SteadyClock::now()};
(gdb) 
2956	   std::shared_ptr<CWallet> walletInstance(new CWallet(chain, name, std::move(database)), ReleaseWallet);
(gdb) 
2024-04-03T18:21:49.734108Z [msghand] [logging/timer.h:58] [Log] [lock] Enter: lock contention connman.m_nodes_mutex, ./net.h:1622 started
2024-04-03T18:21:49.734220Z [msghand] [logging/timer.h:58] [Log] [lock] Enter: lock contention connman.m_nodes_mutex, ./net.h:1622 completed (3μs)
1765		_M_enable_shared_from_this_with(_Yp*) noexcept
(gdb) 
2957	   walletInstance->m_keypool_size = std::max(args.GetIntArg("-keypool", DEFAULT_KEYPOOL_SIZE), int64_t{1});
(gdb) 
88	     __new_allocator() _GLIBCXX_USE_NOEXCEPT { }
(gdb) 
2024-04-03T18:21:55.765728Z [addcon] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_reconnections_mutex, net.cpp:3814 started
2024-04-03T18:21:55.765826Z [addcon] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_reconnections_mutex, net.cpp:3814 completed (1μs)
2957	   walletInstance->m_keypool_size = std::max(args.GetIntArg("-keypool", DEFAULT_KEYPOOL_SIZE), int64_t{1});
(gdb) 
88	     __new_allocator() _GLIBCXX_USE_NOEXCEPT { }
(gdb) 
1665	     get() const noexcept
(gdb) 
2024-04-03T18:21:59.177777Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_reconnections_mutex, net.cpp:1923 started
2024-04-03T18:21:59.177864Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_reconnections_mutex, net.cpp:1923 completed (1μs)
2958	   walletInstance->m_notify_tx_changed_script = args.GetArg("-walletnotify", "");
(gdb) 
2024-04-03T18:22:01.358006Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_nodes_mutex, net.cpp:1860 started
2024-04-03T18:22:01.358112Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_nodes_mutex, net.cpp:1860 completed (1μs)
1665	     get() const noexcept
(gdb) 
2024-04-03T18:22:02.173997Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_reconnections_mutex, net.cpp:1923 started
2024-04-03T18:22:02.174068Z [net] [logging/timer.h:58] [Log] [lock] Enter: lock contention m_reconnections_mutex, net.cpp:1923 completed (3μs)
2024-04-03T18:22:02.174550Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Wallet file version = 10500, last client version = 279900
2024-04-03T18:22:02.743008Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Descriptors: 8, Descriptor Keys: 1 plaintext, 0 encrypted, 1 total.
2024-04-03T18:22:02.920795Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Setting spkMan to active: id = 7bb07d3df110f36af92db5568fb8d4cc1381dd0a6d24b17182ed87cad6ab1d33, type = legacy, internal = false
2024-04-03T18:22:02.920836Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Setting spkMan to active: id = 5cb8f1604559d7b3612008ed3307ca1e21328301d1117b3acdd8b22d5b277219, type = p2sh-segwit, internal = false
2024-04-03T18:22:02.920851Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Setting spkMan to active: id = 68a4834fa805e997434b5c4f2f31625be6f3c5aebae0757293c4215675614a1b, type = bech32, internal = false
2024-04-03T18:22:02.920864Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Setting spkMan to active: id = 19d3e9f0d167b24e3c5330462a0c6cbc3d6e4e06e469967a395835102c0aea4a, type = bech32m, internal = false
2024-04-03T18:22:02.920891Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Setting spkMan to active: id = 09212e585c214fb06d197863920ed50181b984dc6bace73a865ff06a84ec3e61, type = legacy, internal = true
2024-04-03T18:22:02.920907Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Setting spkMan to active: id = 05db3056830116eafc425f192ee58033d44772bbf3bdd62ab50e8d014ecab772, type = p2sh-segwit, internal = true
2024-04-03T18:22:02.920919Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Setting spkMan to active: id = 2fe605d1acd8e46f55fbb47c8162545449df0ab59839219a7541b770a948fa3c, type = bech32, internal = true
2024-04-03T18:22:02.920932Z [httpworker.0] [wallet/wallet.h:933] [WalletLogPrintf] [funds] Setting spkMan to active: id = 115308b94096b7f96245e3ed280290ac5c627c5d666abf5249e4a16bcd5ac79e, type = bech32m, internal = true
2963	   if (nLoadWalletRet != DBErrors::LOAD_OK) {

One thing that jumps out to me as possibly being problematic, depending on what's being debugged, is that the line bool rescan_required = false; is optimized away and no longer appears when going step by step. This is not necessarily a problem as it's still fairly easy to follow what's going on and the variable's value can be checked even though the debugger doesn't indicate that it was initialized.

Another thing that is kind of annoying is the appearance of the __new_allocator() and get() calls. We don't see these in the actual code and their appearance means stepping through some more lines that are probably irrelevant to debugging.

@theuni
Copy link
Member

theuni commented Apr 3, 2024

@achow101 Yeah, I see the same. Sadly that's the trade-off. Basically -O0 is a poor approximation of what real optimized code will look like. But anything above is bound to optimize some things out.

So we have to make a choice: pure debug-ability (including things like inlines which don't actually exist), or more realistic binaries while sacrificing some source code in the debugger. Personally I prefer the latter, but you probably live in gdb more than me :)

@theuni
Copy link
Member

theuni commented Apr 3, 2024

Note that for local hacking (with clang), you can use:

diff --git a/src/wallet/wallet.cpp b/src/wallet/wallet.cpp
index 96c4397504..6bc408e843 100644
--- a/src/wallet/wallet.cpp
+++ b/src/wallet/wallet.cpp
@@ -2944,7 +2944,7 @@ std::unique_ptr<WalletDatabase> MakeWalletDatabase(const std::string& name, cons
     return MakeDatabase(wallet_path, options, status, error_string);
 }

-std::shared_ptr<CWallet> CWallet::Create(WalletContext& context, const std::string& name, std::unique_ptr<WalletDatabase> database, uint64_t wallet_creation_flags, bilingual_str& error, std::vector<bilingual_str>& warnings)
+std::shared_ptr<CWallet> CWallet::Create(WalletContext& context, const std::string& name, std::unique_ptr<WalletDatabase> database, uint64_t wallet_creation_flags, bilingual_str& error, std::vector<bilingual_str>& warnings) __attribute__ ((optnone))
 {
     interfaces::Chain* chain = context.chain;
     ArgsManager& args = *Assert(context.args);

To get the best of both worlds:

Thread 1 "b-test" hit Breakpoint 1, wallet::CWallet::Create (context=..., name="/tmp/test_common_Bitcoin Core/231b391a2079bb9568d880b8e884ab0b1c6a21c39361735a83653cf8256a247e/test_wallet_2950041828", database=std::unique_ptr<wallet::WalletDatabase> = {...}, wallet_creation_flags=25769803776, error=..., warnings=std::vector of length 0, capacity 0) at ./src/wallet/wallet.cpp:2949
2949	    interfaces::Chain* chain = context.chain;
(gdb) n
2950	    ArgsManager& args = *Assert(context.args);
(gdb)
2951	    const std::string& walletFile = database->Filename();
(gdb)
2953	    const auto start{SteadyClock::now()};
(gdb)
2956	    std::shared_ptr<CWallet> walletInstance(new CWallet(chain, name, std::move(database)), ReleaseWallet);
(gdb)
2957	    walletInstance->m_keypool_size = std::max(args.GetIntArg("-keypool", DEFAULT_KEYPOOL_SIZE), int64_t{1});
(gdb)
2958	    walletInstance->m_notify_tx_changed_script = args.GetArg("-walletnotify", "");
(gdb)
2961	    bool rescan_required = false;

@fanquake
Copy link
Member Author

fanquake commented Apr 4, 2024

One thing to investigate is if -ggdb(n) is useful here at all.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

6 participants