From 684a1582971d75b9bb6abd8c1926d1bc80f37a2a Mon Sep 17 00:00:00 2001 From: Yilin Chen Date: Tue, 31 Aug 2021 16:22:27 +0800 Subject: [PATCH 1/2] RFC: Keep Key Logs Signed-off-by: Yilin Chen --- text/0000-keep-key-logs.md | 63 ++++++++++++++++++++++++++++++++++++++ 1 file changed, 63 insertions(+) create mode 100644 text/0000-keep-key-logs.md diff --git a/text/0000-keep-key-logs.md b/text/0000-keep-key-logs.md new file mode 100644 index 00000000..dff174a1 --- /dev/null +++ b/text/0000-keep-key-logs.md @@ -0,0 +1,63 @@ +# RFC: Keep Key Logs + +- RFC PR: +- Tracking issue: + +## Motivation + +To address https://github.com/tikv/tikv/issues/10841, we decide to prioritize availability over log completeness thus switch the overflow strategy of logger from `Block` to `Drop`. + +However, some logs are useful for diagnosis in practice. We heavily depend on logs to investigate bugs or abnormalities of the system. If all logs are dropped randomly, reasoning about the raftstore or transaction issues may be impossible. + +Therefore, it is only a temporary workaround to simply drop overflowed logs. We hope to keep logs that are important for diagnosis if possible. + +## Detailed design + +The problem is that we don't define which logs are important. Whether a log is important for diagnosis is not related to the log level. + +For example, we prefer to keep info level logs in the raftstore rather than keep warn level logs in the coprocessor module. The former one is critical for finding out how each region evolves while the latter one may be only a retryable error. + +So, these important logs deserve to have another set of macros: + +- `key_crit!` +- `key_error!` +- `key_warn!` +- `key_info!` +- `key_debug!` +- `key_trace!` + +Logs from these macros should not be dropped as they are key information. These macros should **NOT** be abused. + +### Reserved space for key logs + +We use async logging to reduce the performance impact on the working threads. The order of logs must be retained, so it is a good idea to still have only one channel to guarantee this property. That is to say, the key logs are pushed to the same channel as normal logs. + +But we do not want normal logs to occupy all spaces of the channel. The solution is that we set a threshold for normal logs. + +If the message number in the channel goes beyond half of the channel capacity, normal logs are refused and dropped. Key logs can be pushed to the channel until the channel is totally full. + +In this way, we make sure at least half of the total capacity is always available to key logs. + +### Overflow fallback + +Despite the design of key logs, it is still possible we abuse key logs and make the channel full. + +The principle is that availability should be never sacrificed. So we must not block the sender on overflow, nor use an unbounded channel which has the risk of OOM. But we still hope to keep the key logs. + +The fallback solution is to write logs to a file synchronously. + +If key logs fail to be sent to the channel, they are formatted at the sender thread and written to the fallback log file. Without disk syncing, these writes should finish with very small latency and reasonable throughput. Then the working threads will not be badly affected and we do not really drop any key logs. + +### Changes to `slog` modules + +Key logs are distinguished by its tag. `key_info!(...)` is a macro equivalent to `info!(#"key_log", ...)`. + +Add a new method `reserve_for_key_logs(self, fallback_path: &Path)` to `AsyncBuilder`. + +If this option is set, the length of the channel should be checked in `::log` if the tag name is different from `"key_log"`. If the length is bigger than half the capacity, the log should be dropped. + +## Unresolved questions + +- Naming of the key log macros +- Channel capacity +- Configuration and filename of the fallback log file \ No newline at end of file From 25d8df03ca2ac49dcf2a8b0a69f42777a952b209 Mon Sep 17 00:00:00 2001 From: Yilin Chen Date: Tue, 31 Aug 2021 19:36:11 +0800 Subject: [PATCH 2/2] rewording "synchronously" Signed-off-by: Yilin Chen --- text/{0000-keep-key-logs.md => 0073-keep-key-logs.md} | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) rename text/{0000-keep-key-logs.md => 0073-keep-key-logs.md} (95%) diff --git a/text/0000-keep-key-logs.md b/text/0073-keep-key-logs.md similarity index 95% rename from text/0000-keep-key-logs.md rename to text/0073-keep-key-logs.md index dff174a1..c74c0a5e 100644 --- a/text/0000-keep-key-logs.md +++ b/text/0073-keep-key-logs.md @@ -44,7 +44,7 @@ Despite the design of key logs, it is still possible we abuse key logs and make The principle is that availability should be never sacrificed. So we must not block the sender on overflow, nor use an unbounded channel which has the risk of OOM. But we still hope to keep the key logs. -The fallback solution is to write logs to a file synchronously. +The fallback solution is to write logs to a file directly in the working threads. If key logs fail to be sent to the channel, they are formatted at the sender thread and written to the fallback log file. Without disk syncing, these writes should finish with very small latency and reasonable throughput. Then the working threads will not be badly affected and we do not really drop any key logs. @@ -60,4 +60,4 @@ If this option is set, the length of the channel should be checked in `