[lldb] Introduce an always-on system log category/channel #108495
Conversation
JDevlieghere
requested review from
kastiglione,
adrian-prantl,
labath,
clayborg and
jimingham
|
@llvm/pr-subscribers-lldb Author: Jonas Devlieghere (JDevlieghere) ChangesAdd an "always on" log category and channel. Unlike other, existing log channels, it is not exposed to users. The channel is meant to be used sparsely and deliberately for logging high-value information to the system log. We have a similar concept in the downstream Swift fork and this has proven to be extremely valuable. This is especially true on macOS where system log messages are automatically captured as part of a sysdiagnose. This patch revives https://reviews.llvm.org/D135621 although the purpose is slightly different (logging to the system log rather than to a ring buffer dumped as part of the diagnostics). This patch addresses all the remaining oustanding comments. Full diff: https://github.com/llvm/llvm-project/pull/108495.diff 7 Files Affected:
diff --git a/lldb/include/lldb/Host/Host.h b/lldb/include/lldb/Host/Host.h
index 9d0994978402f7..1ca89fa056aa93 100644
--- a/lldb/include/lldb/Host/Host.h
+++ b/lldb/include/lldb/Host/Host.h
@@ -31,6 +31,22 @@ class ProcessInstanceInfo;
class ProcessInstanceInfoMatch;
typedef std::vector<ProcessInstanceInfo> ProcessInstanceInfoList;
+// Always on system log category and channel.
+enum class SystemLog : Log::MaskType {
+ System = Log::ChannelFlag<0>,
+ LLVM_MARK_AS_BITMASK_ENUM(System)
+};
+
+LLVM_ENABLE_BITMASK_ENUMS_IN_NAMESPACE();
+
+class LogChannelSystem {
+public:
+ static void Initialize();
+ static void Terminate();
+};
+
+template <> Log::Channel &LogChannelFor<SystemLog>();
+
// Exit Type for inferior processes
struct WaitStatus {
enum Type : uint8_t {
diff --git a/lldb/include/lldb/Utility/LLDBLog.h b/lldb/include/lldb/Utility/LLDBLog.h
index c7de41e74e85bd..b3e0e77514b8be 100644
--- a/lldb/include/lldb/Utility/LLDBLog.h
+++ b/lldb/include/lldb/Utility/LLDBLog.h
@@ -49,6 +49,7 @@ enum class LLDBLog : Log::MaskType {
Watchpoints = Log::ChannelFlag<30>,
OnDemand = Log::ChannelFlag<31>,
Source = Log::ChannelFlag<32>,
+ AlwaysOn = Log::ChannelFlag<32>,
LLVM_MARK_AS_BITMASK_ENUM(OnDemand),
};
diff --git a/lldb/include/lldb/Utility/Log.h b/lldb/include/lldb/Utility/Log.h
index 27707c17f9b824..bcb022093c9001 100644
--- a/lldb/include/lldb/Utility/Log.h
+++ b/lldb/include/lldb/Utility/Log.h
@@ -165,13 +165,14 @@ class Log final {
friend class Log;
public:
+ const bool internal = false;
const llvm::ArrayRef<Category> categories;
const MaskType default_flags;
template <typename Cat>
constexpr Channel(llvm::ArrayRef<Log::Category> categories,
- Cat default_flags)
- : log_ptr(nullptr), categories(categories),
+ Cat default_flags, bool internal = false)
+ : log_ptr(nullptr), internal(internal), categories(categories),
default_flags(MaskType(default_flags)) {
static_assert(
std::is_same<Log::MaskType, std::underlying_type_t<Cat>>::value);
diff --git a/lldb/source/Host/common/Host.cpp b/lldb/source/Host/common/Host.cpp
index f08adea6546ae1..3baf40a4700ffb 100644
--- a/lldb/source/Host/common/Host.cpp
+++ b/lldb/source/Host/common/Host.cpp
@@ -125,6 +125,25 @@ void Host::SystemLog(Severity severity, llvm::StringRef message) {
#endif
#endif
+static constexpr Log::Category g_categories[] = {
+ {{"system"}, {"system log"}, SystemLog::System}};
+
+static Log::Channel g_channel(g_categories, SystemLog::System,
+ /*internal=*/true);
+
+template <> Log::Channel &lldb_private::LogChannelFor<SystemLog>() {
+ return g_channel;
+}
+
+void LogChannelSystem::Initialize() {
+ Log::Register("system", g_channel);
+ const uint32_t log_options = LLDB_LOG_OPTION_PREPEND_THREAD_NAME;
+ Log::EnableLogChannel(std::make_shared<SystemLogHandler>(), log_options,
+ "system", {"all"}, llvm::nulls());
+}
+
+void LogChannelSystem::Terminate() { Log::Unregister("system"); }
+
#if !defined(__APPLE__) && !defined(_WIN32)
static thread_result_t
MonitorChildProcessThreadFunction(::pid_t pid,
diff --git a/lldb/source/Host/common/HostInfoBase.cpp b/lldb/source/Host/common/HostInfoBase.cpp
index 5c44c2f38b2879..89dfe4a9e9baa3 100644
--- a/lldb/source/Host/common/HostInfoBase.cpp
+++ b/lldb/source/Host/common/HostInfoBase.cpp
@@ -76,9 +76,11 @@ static HostInfoBase::SharedLibraryDirectoryHelper *g_shlib_dir_helper = nullptr;
void HostInfoBase::Initialize(SharedLibraryDirectoryHelper *helper) {
g_shlib_dir_helper = helper;
g_fields = new HostInfoBaseFields();
+ LogChannelSystem::Initialize();
}
void HostInfoBase::Terminate() {
+ LogChannelSystem::Terminate();
g_shlib_dir_helper = nullptr;
delete g_fields;
g_fields = nullptr;
diff --git a/lldb/source/Utility/Log.cpp b/lldb/source/Utility/Log.cpp
index 6713a5bd758204..040bd47606ce18 100644
--- a/lldb/source/Utility/Log.cpp
+++ b/lldb/source/Utility/Log.cpp
@@ -245,6 +245,11 @@ bool Log::DisableLogChannel(llvm::StringRef channel,
error_stream << llvm::formatv("Invalid log channel '{0}'.\n", channel);
return false;
}
+ if (iter->second.m_channel.internal) {
+ error_stream << llvm::formatv(
+ "Cannot disable internal log channel '{0}'.\n", channel);
+ return false;
+ }
MaskType flags = categories.empty()
? std::numeric_limits<MaskType>::max()
: GetFlags(error_stream, *iter, categories);
@@ -296,8 +301,10 @@ void Log::ForEachChannelCategory(
std::vector<llvm::StringRef> Log::ListChannels() {
std::vector<llvm::StringRef> result;
- for (const auto &channel : *g_channel_map)
- result.push_back(channel.first());
+ for (const auto &entry : *g_channel_map) {
+ if (!entry.second.m_channel.internal)
+ result.push_back(entry.first());
+ }
return result;
}
@@ -307,8 +314,10 @@ void Log::ListAllLogChannels(llvm::raw_ostream &stream) {
return;
}
- for (const auto &channel : *g_channel_map)
- ListCategories(stream, channel);
+ for (const auto &entry : *g_channel_map) {
+ if (!entry.second.m_channel.internal)
+ ListCategories(stream, entry);
+ }
}
bool Log::GetVerbose() const {
diff --git a/lldb/test/Shell/Host/TestSytemLogChannel.test b/lldb/test/Shell/Host/TestSytemLogChannel.test
new file mode 100644
index 00000000000000..9ac4985da6164e
--- /dev/null
+++ b/lldb/test/Shell/Host/TestSytemLogChannel.test
@@ -0,0 +1,3 @@
+RUN: %lldb -o 'log list' -o 'log disable system' 2>&1 | FileCheck %s
+CHECK-NOT: Logging categories for 'system'
+CHECK: Cannot disable internal log channel 'system'.
|
JDevlieghere
force-pushed
the
always-on-system-log
branch
from
e9704ca to
734088d
Compare
| @@ -0,0 +1,3 @@ | |||
| RUN: %lldb -o 'log list' -o 'log disable system' 2>&1 | FileCheck %s | |||
| CHECK-NOT: Logging categories for 'system' | |||
| CHECK: Cannot disable internal log channel 'system'. | |||
There was a problem hiding this comment.
This is bikeshedding but perhaps:
`system` is an internal log channel, internal channels can not be disabled.
Just to be extra clear that we're not just printing "internal log" for the sake of it, it's the reason why it cannot be disabled.
(...maybe I am too used to software lying to me and should relax 🤣 )
lldb/include/lldb/Host/Host.h
Outdated
| @@ -31,6 +31,22 @@ class ProcessInstanceInfo; | |||
| class ProcessInstanceInfoMatch; | |||
| typedef std::vector<ProcessInstanceInfo> ProcessInstanceInfoList; | |||
|
|
|||
| // Always on system log category and channel. | |||
There was a problem hiding this comment.
So is the log naming system system or for now is it just system and we might add sub-channels later?
There was a problem hiding this comment.
I think we should have a comment that explains what this channel is supposed to be used for?
This is presumably because:
Users can still list it, I see that from the test, but that's fine we don't need to lie about its existence. If someone suspects that a relevant message might be in this channel how do they look at it? Do they crash lldb / use a command to dump an archive of logs?
What is an example of that? So that folks (aka me) have an idea what might go here for other OSs. Is it stuff like this process was killed for this reason, this system resource had to be cleared, that sort of thing? |
Does this mean someone has already been putting non-MacOS messages in there in the Swift fork? Would be interested to know what those are. |
|
My first thought when seeing (before opening the phabricator patch) this was "wouldn't this be better off as a separate API". After opening the link, I saw that this was the last comment on it as well. So, what has changed since then? My think is that, our logging API is a fairly complex piece of machinery, and I think this is largely due to the fact that we're allowing the user to customize it (change the target, verbosity, etc.). For the this log channel, you basically take away all of that, so what's the point in going through all of that? Why not just have a single |
Actually the test is testing that it cannot (
That depends on the system they're on: on macOS that would be by looking at Console.app. On Linux it's a file in
A really trivial example is logging the lldb version in the system log, which is something we do already do on the Swift fork. At Apple we have different toolchains with different versions of LLDB and surprisingly often a bug report will state the wrong version of LLDB. At this point this has probably saved me hours of wasted time.
Not quite, the Swift fork uses its own category & channel. Unlike the always-on channel I'm proposing here, the Swift one is meant to be user-visible. Users can generate the log file with a command ( If you look at the implementation, you can see that it's using a T-loghandler that writes both to a buffer and to the system log.
I wouldn't say anything has changed, but here's why I'm proposing the log channel approach again:
Ultimately I care more about the functionality than the implementation so I'm not opposed to the separate API, but I also want to encourage adoption across LLDB. |
I'm all for code reuse, and reusing some part of the logging machinery for this makes sense to me. The thing I'm not sure about is whether this is plugging into the machinery at the right level. The most irritating part is the I think this would look better if the flag wasn't there. Like, what if we had a separate way to create/register one of these "system" channels -- one which does not involve putting it in a list with all the other channels. Maybe the (The |
JDevlieghere
force-pushed
the
always-on-system-log
branch
from
734088d to
2bf9eaf
Compare
|
Rebased + addressed @labath and @adrian-prantl's feedback. |
JDevlieghere
force-pushed
the
always-on-system-log
branch
from
2bf9eaf to
c2d2758
Compare
| @@ -83,6 +85,9 @@ llvm::Error SystemInitializerFull::Initialize() { | |||
| // Use the Debugger's LLDBAssert callback. | |||
| SetLLDBAssertCallback(Debugger::AssertCallback); | |||
|
|
|||
| // Log the LLDB version to the system log. | |||
There was a problem hiding this comment.
I don't think this tells us anything new.
lldb/include/lldb/Utility/Log.h
Outdated
| @@ -272,6 +272,12 @@ class Log final { | |||
| void VAFormatf(llvm::StringRef file, llvm::StringRef function, | |||
| const char *format, va_list args); | |||
|
|
|||
| void Enable(const std::shared_ptr<LogHandler> &handler_sp, | |||
| uint32_t options = 0, | |||
| MaskType flags = std::numeric_limits<Log::MaskType>::max()); | |||
There was a problem hiding this comment.
The log channels have a concept of a default set of categories, so if we're going to have a default here, it better be it. That could be achieved by making this an optional<MaskType> (and then you can also simplify the code in EnableLogChannel).
| @@ -20,6 +20,8 @@ | |||
| #include "llvm/Support/CommandLine.h" | |||
| #include "llvm/Support/TargetSelect.h" | |||
|
|
|||
| #include "lldb/Version/Version.h" | |||
There was a problem hiding this comment.
Group this with the other lldb includes?
Add an "always on" log category and channel. Unlike other, existing log channels, it is not exposed to users. The channel is meant to be used sparsely and deliberately for logging high-value information to the system log. We have a similar concept in the downstream Swift fork and this has proven to be extremely valuable. This is especially true on macOS where system log messages are automatically captured as part of a sysdiagnose. This patch revives https://reviews.llvm.org/D135621 although the purpose is slightly different (logging to the system log rather than to a ring buffer dumped as part of the diagnostics). This patch addresses all the remaining outstanding comments.
JDevlieghere
force-pushed
the
always-on-system-log
branch
from
c2d2758 to
98f1b5e
Compare
|
Hi, could this patch be the cause of lldb-aarch64-windows bot failure ? |
Add an "always on" log category and channel. Unlike other, existing log channels, it is not exposed to users. The channel is meant to be used sparsely and deliberately for logging high-value information to the system log. We have a similar concept in the downstream Swift fork and this has proven to be extremely valuable. This is especially true on macOS where system log messages are automatically captured as part of a sysdiagnose.
Add an "always on" log category and channel. Unlike other, existing log channels, it is not exposed to users. The channel is meant to be used sparsely and deliberately for logging high-value information to the system log.
We have a similar concept in the downstream Swift fork and this has proven to be extremely valuable. This is especially true on macOS where system log messages are automatically captured as part of a sysdiagnose.
This patch revives https://reviews.llvm.org/D135621 although the purpose is slightly different (logging to the system log rather than to a ring buffer dumped as part of the diagnostics). This patch addresses all the remaining oustanding comments.