Bitcoin logging currently has the following issues:
1. parameters of the log are evaluated before if it will be printed
This is a performance issue as many logs convert objects like int256 into hex std::strings for display. This requires memory allocations and looping.
This is not theoretical: random sampling in my giga_perf work shows threads spending significant time in logging even when no logs are enabled.
2. log selection happens inefficiently.
See LogAcceptCategory The log category is a char* that is converted into a std::string that is looked up in a std::set. There are actually 3 lookups per check since the all options, "" and "1" are also checked. This requires memory allocations and container lookups.
3. thread specific data
the log category set is placed in thread specific data for no discernable purpose (perhaps performance), or the ability to turn on per-thread logging via gdb?
4. can't change logging while program is running
Because the log category set is placed in thread specific data, its impossible modify that info from a RPC (bitcoin-cli) handler thread.
5. Deleting the log file "debug.log" while program is running loses all new logs (linux).
However, we want to keep logging simple -- in fact, I want it to be simpler than the above -- and not create yet-another-dependency to a fancy 3rd party logging toolkit.
New logging function:
1. Macros: LOG(category, "printf-string", args) -- replaces LogPrint
LOGA("printf-string", args) -- replaces LogPrintf (stands for log alert, since its always printed)
2. logs that are "on" are defined by a global "uint64_t categoriesEnabled", under the Logging namespace. Each bit corresponds to a category.
3. category is a bit defined in an enum, not a string. There is a translation between a string and the enum. This translation is defined near the enum, to make it easy for a developer to add new logging categories.
Initialization code uses the string->enum value translation to define what logs are on.
4. categories are defined by short 3-letter all caps names and placed under the "Logging" namespace. However the 1st parameter to the LOG macro
is evaluated under the Logging namespace so the short name is allowed as a parameter to LOG without polluting the global namespace. See example code below.
5. logical OR-ing of categories:
LOG(NET | BLK, "foo") means that if NET or BLK is enabled, this log will be issued.
6. LOG macro determines that the log category is enabled before it evaluates the printf parameters
7. new RPC command "bitcoin-cli log <case insensitive category> [boolean: enable|disable|1|0|true|false|on|off]"
Also allow any case versions of the bool parameter. Please make a utility function that accepts a string and returns a boolean or throws and exception so that this function can be used throughout the RPC commands.
if the bool parameter is not supplied return a boolean specifying the current log state.
allow a special case string "all" that will turn all logs on or off
8. Periodically (but not every time LOG is called) check to see if the log output file has been deleted. If so, close and reopen.
9. Add unit tests in src/test
10. Create a pull request (PR) for this new log function.
11. After the PR for this LOG function is merged, do a mass conversion of LogPrint(...) to the new LOG(...) function.
#include <stdio.h>
namespace Logging
{
enum
{
NET=1,
BLK=2,
LCK=0x4,
THN=0x8
};
}
#define LOG(category, string) { using namespace Logging; printf("%d:%s\n", category,string); }
int main(void)
{
LOG(NET, "test");
// Note that NET only works without a namespace qualifier inside the LOG macro. For example, this is an error.
// printf("%s", NET);
}
1. parameters of the log are evaluated before if it will be printed
This is a performance issue as many logs convert objects like int256 into hex std::strings for display. This requires memory allocations and looping.
This is not theoretical: random sampling in my giga_perf work shows threads spending significant time in logging even when no logs are enabled.
2. log selection happens inefficiently.
See LogAcceptCategory The log category is a char* that is converted into a std::string that is looked up in a std::set. There are actually 3 lookups per check since the all options, "" and "1" are also checked. This requires memory allocations and container lookups.
3. thread specific data
the log category set is placed in thread specific data for no discernable purpose (perhaps performance), or the ability to turn on per-thread logging via gdb?
4. can't change logging while program is running
Because the log category set is placed in thread specific data, its impossible modify that info from a RPC (bitcoin-cli) handler thread.
5. Deleting the log file "debug.log" while program is running loses all new logs (linux).
However, we want to keep logging simple -- in fact, I want it to be simpler than the above -- and not create yet-another-dependency to a fancy 3rd party logging toolkit.
New logging function:
1. Macros: LOG(category, "printf-string", args) -- replaces LogPrint
LOGA("printf-string", args) -- replaces LogPrintf (stands for log alert, since its always printed)
2. logs that are "on" are defined by a global "uint64_t categoriesEnabled", under the Logging namespace. Each bit corresponds to a category.
3. category is a bit defined in an enum, not a string. There is a translation between a string and the enum. This translation is defined near the enum, to make it easy for a developer to add new logging categories.
Initialization code uses the string->enum value translation to define what logs are on.
4. categories are defined by short 3-letter all caps names and placed under the "Logging" namespace. However the 1st parameter to the LOG macro
is evaluated under the Logging namespace so the short name is allowed as a parameter to LOG without polluting the global namespace. See example code below.
5. logical OR-ing of categories:
LOG(NET | BLK, "foo") means that if NET or BLK is enabled, this log will be issued.
6. LOG macro determines that the log category is enabled before it evaluates the printf parameters
7. new RPC command "bitcoin-cli log <case insensitive category> [boolean: enable|disable|1|0|true|false|on|off]"
Also allow any case versions of the bool parameter. Please make a utility function that accepts a string and returns a boolean or throws and exception so that this function can be used throughout the RPC commands.
if the bool parameter is not supplied return a boolean specifying the current log state.
allow a special case string "all" that will turn all logs on or off
8. Periodically (but not every time LOG is called) check to see if the log output file has been deleted. If so, close and reopen.
9. Add unit tests in src/test
10. Create a pull request (PR) for this new log function.
11. After the PR for this LOG function is merged, do a mass conversion of LogPrint(...) to the new LOG(...) function.
#include <stdio.h>
namespace Logging
{
enum
{
NET=1,
BLK=2,
LCK=0x4,
THN=0x8
};
}
#define LOG(category, string) { using namespace Logging; printf("%d:%s\n", category,string); }
int main(void)
{
LOG(NET, "test");
// Note that NET only works without a namespace qualifier inside the LOG macro. For example, this is an error.
// printf("%s", NET);
}
