henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 1 | /* |
| 2 | * Copyright 2004 The WebRTC Project Authors. All rights reserved. |
| 3 | * |
| 4 | * Use of this source code is governed by a BSD-style license |
| 5 | * that can be found in the LICENSE file in the root of the source |
| 6 | * tree. An additional intellectual property rights grant can be found |
| 7 | * in the file PATENTS. All contributing project authors may |
| 8 | * be found in the AUTHORS file in the root of the source tree. |
| 9 | */ |
| 10 | |
Mirko Bonadei | 92ea95e | 2017-09-15 04:47:31 | [diff] [blame] | 11 | #include "rtc_base/logging.h" |
Yves Gerey | 3e70781 | 2018-11-28 15:47:49 | [diff] [blame] | 12 | |
Artem Titov | 6a4a146 | 2019-11-26 15:24:46 | [diff] [blame] | 13 | #if RTC_LOG_ENABLED() |
| 14 | |
Yves Gerey | 3e70781 | 2018-11-28 15:47:49 | [diff] [blame] | 15 | #include <string.h> |
Jonas Olsson | a4d8737 | 2019-07-05 17:08:33 | [diff] [blame] | 16 | |
Yves Gerey | 3e70781 | 2018-11-28 15:47:49 | [diff] [blame] | 17 | #include <algorithm> |
| 18 | |
Ali Tofigh | 6364d08 | 2022-03-14 12:32:04 | [diff] [blame] | 19 | #include "absl/strings/string_view.h" |
Tommi | fef0500 | 2018-02-27 12:51:08 | [diff] [blame] | 20 | #include "rtc_base/arraysize.h" |
| 21 | #include "rtc_base/checks.h" |
| 22 | #include "rtc_base/event.h" |
Tommi | fef0500 | 2018-02-27 12:51:08 | [diff] [blame] | 23 | #include "rtc_base/platform_thread.h" |
Steve Anton | 10542f2 | 2019-01-11 17:11:00 | [diff] [blame] | 24 | #include "rtc_base/time_utils.h" |
Evan Shrubsole | 7765f9e | 2022-04-25 09:04:12 | [diff] [blame] | 25 | #include "test/gmock.h" |
Yves Gerey | 3e70781 | 2018-11-28 15:47:49 | [diff] [blame] | 26 | #include "test/gtest.h" |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 27 | |
| 28 | namespace rtc { |
| 29 | |
Mirko Bonadei | 70ed471 | 2022-08-03 12:49:40 | [diff] [blame] | 30 | namespace { |
| 31 | |
| 32 | #if defined(WEBRTC_WIN) |
| 33 | constexpr char kFakeFilePath[] = "some\\path\\myfile.cc"; |
| 34 | #else |
| 35 | constexpr char kFakeFilePath[] = "some/path/myfile.cc"; |
| 36 | #endif |
| 37 | |
| 38 | } // namespace |
| 39 | |
Niels Möller | ed3f9ec | 2021-03-29 10:12:29 | [diff] [blame] | 40 | class LogSinkImpl : public LogSink { |
Niels Möller | ff3dd0c | 2018-06-20 08:27:53 | [diff] [blame] | 41 | public: |
Niels Möller | ed3f9ec | 2021-03-29 10:12:29 | [diff] [blame] | 42 | explicit LogSinkImpl(std::string* log_data) : log_data_(log_data) {} |
Tommi | 0eefb4d | 2015-05-23 07:54:07 | [diff] [blame] | 43 | |
Yves Gerey | 665174f | 2018-06-19 13:03:05 | [diff] [blame] | 44 | template <typename P> |
Niels Möller | ed3f9ec | 2021-03-29 10:12:29 | [diff] [blame] | 45 | explicit LogSinkImpl(P* p) {} |
Tommi | 0eefb4d | 2015-05-23 07:54:07 | [diff] [blame] | 46 | |
| 47 | private: |
| 48 | void OnLogMessage(const std::string& message) override { |
Ali Tofigh | 6364d08 | 2022-03-14 12:32:04 | [diff] [blame] | 49 | OnLogMessage(absl::string_view(message)); |
| 50 | } |
| 51 | void OnLogMessage(absl::string_view message) override { |
| 52 | log_data_->append(message.begin(), message.end()); |
Tommi | 0eefb4d | 2015-05-23 07:54:07 | [diff] [blame] | 53 | } |
Niels Möller | ed3f9ec | 2021-03-29 10:12:29 | [diff] [blame] | 54 | std::string* const log_data_; |
Tommi | 0eefb4d | 2015-05-23 07:54:07 | [diff] [blame] | 55 | }; |
| 56 | |
Tommi | fef0500 | 2018-02-27 12:51:08 | [diff] [blame] | 57 | class LogMessageForTesting : public LogMessage { |
| 58 | public: |
| 59 | LogMessageForTesting(const char* file, |
| 60 | int line, |
| 61 | LoggingSeverity sev, |
| 62 | LogErrorContext err_ctx = ERRCTX_NONE, |
| 63 | int err = 0) |
| 64 | : LogMessage(file, line, sev, err_ctx, err) {} |
| 65 | |
| 66 | const std::string& get_extra() const { return extra_; } |
Paulina Hensman | f1e3cb4 | 2018-06-20 12:07:05 | [diff] [blame] | 67 | #if defined(WEBRTC_ANDROID) |
Mirko Bonadei | 96191f8 | 2022-08-03 08:12:33 | [diff] [blame] | 68 | const char* get_tag() const { return log_line_.tag().data(); } |
Paulina Hensman | f1e3cb4 | 2018-06-20 12:07:05 | [diff] [blame] | 69 | #endif |
Tommi | fef0500 | 2018-02-27 12:51:08 | [diff] [blame] | 70 | |
| 71 | // Returns the contents of the internal log stream. |
| 72 | // Note that parts of the stream won't (as is) be available until *after* the |
| 73 | // dtor of the parent class has run. So, as is, this only represents a |
| 74 | // partially built stream. |
| 75 | std::string GetPrintStream() { |
| 76 | RTC_DCHECK(!is_finished_); |
| 77 | is_finished_ = true; |
| 78 | FinishPrintStream(); |
Jonas Olsson | d8c5078 | 2018-09-07 09:21:28 | [diff] [blame] | 79 | return print_stream_.Release(); |
Tommi | fef0500 | 2018-02-27 12:51:08 | [diff] [blame] | 80 | } |
| 81 | |
| 82 | private: |
| 83 | bool is_finished_ = false; |
| 84 | }; |
| 85 | |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 86 | // Test basic logging operation. We should get the INFO log but not the VERBOSE. |
| 87 | // We should restore the correct global state at the end. |
| 88 | TEST(LogTest, SingleStream) { |
deadbeef | 37f5ecf | 2017-02-27 22:06:41 | [diff] [blame] | 89 | int sev = LogMessage::GetLogToStream(nullptr); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 90 | |
| 91 | std::string str; |
Niels Möller | ed3f9ec | 2021-03-29 10:12:29 | [diff] [blame] | 92 | LogSinkImpl stream(&str); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 93 | LogMessage::AddLogToStream(&stream, LS_INFO); |
| 94 | EXPECT_EQ(LS_INFO, LogMessage::GetLogToStream(&stream)); |
| 95 | |
Mirko Bonadei | 675513b | 2017-11-09 10:09:25 | [diff] [blame] | 96 | RTC_LOG(LS_INFO) << "INFO"; |
| 97 | RTC_LOG(LS_VERBOSE) << "VERBOSE"; |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 98 | EXPECT_NE(std::string::npos, str.find("INFO")); |
| 99 | EXPECT_EQ(std::string::npos, str.find("VERBOSE")); |
| 100 | |
Jonas Olsson | f2ce37c | 2018-09-12 13:32:47 | [diff] [blame] | 101 | int i = 1; |
| 102 | long l = 2l; |
| 103 | long long ll = 3ll; |
| 104 | |
| 105 | unsigned int u = 4u; |
| 106 | unsigned long ul = 5ul; |
| 107 | unsigned long long ull = 6ull; |
| 108 | |
| 109 | std::string s1 = "char*"; |
| 110 | std::string s2 = "std::string"; |
| 111 | std::string s3 = "absl::stringview"; |
Niels Möller | 65835be | 2019-02-04 18:23:58 | [diff] [blame] | 112 | const char* null_string = nullptr; |
Jonas Olsson | f2ce37c | 2018-09-12 13:32:47 | [diff] [blame] | 113 | void* p = reinterpret_cast<void*>(0xabcd); |
| 114 | |
| 115 | // Log all suported types(except doubles/floats) as a sanity-check. |
| 116 | RTC_LOG(LS_INFO) << "|" << i << "|" << l << "|" << ll << "|" << u << "|" << ul |
| 117 | << "|" << ull << "|" << s1.c_str() << "|" << s2 << "|" |
Niels Möller | 65835be | 2019-02-04 18:23:58 | [diff] [blame] | 118 | << absl::string_view(s3) << "|" << p << "|" << null_string |
| 119 | << "|"; |
Jonas Olsson | f2ce37c | 2018-09-12 13:32:47 | [diff] [blame] | 120 | |
| 121 | // Signed integers |
| 122 | EXPECT_NE(std::string::npos, str.find("|1|")); |
| 123 | EXPECT_NE(std::string::npos, str.find("|2|")); |
| 124 | EXPECT_NE(std::string::npos, str.find("|3|")); |
| 125 | |
| 126 | // Unsigned integers |
| 127 | EXPECT_NE(std::string::npos, str.find("|4|")); |
| 128 | EXPECT_NE(std::string::npos, str.find("|5|")); |
| 129 | EXPECT_NE(std::string::npos, str.find("|6|")); |
| 130 | |
| 131 | // Strings |
| 132 | EXPECT_NE(std::string::npos, str.find("|char*|")); |
| 133 | EXPECT_NE(std::string::npos, str.find("|std::string|")); |
| 134 | EXPECT_NE(std::string::npos, str.find("|absl::stringview|")); |
| 135 | |
| 136 | // void* |
| 137 | EXPECT_NE(std::string::npos, str.find("|abcd|")); |
| 138 | |
Niels Möller | 65835be | 2019-02-04 18:23:58 | [diff] [blame] | 139 | // null char* |
| 140 | EXPECT_NE(std::string::npos, str.find("|(null)|")); |
| 141 | |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 142 | LogMessage::RemoveLogToStream(&stream); |
Tommi | 0eefb4d | 2015-05-23 07:54:07 | [diff] [blame] | 143 | EXPECT_EQ(LS_NONE, LogMessage::GetLogToStream(&stream)); |
deadbeef | 37f5ecf | 2017-02-27 22:06:41 | [diff] [blame] | 144 | EXPECT_EQ(sev, LogMessage::GetLogToStream(nullptr)); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 145 | } |
| 146 | |
Per Kjellander | 4d41913 | 2022-09-30 10:50:41 | [diff] [blame] | 147 | TEST(LogTest, LogIfLogIfConditionIsTrue) { |
| 148 | std::string str; |
| 149 | LogSinkImpl stream(&str); |
| 150 | LogMessage::AddLogToStream(&stream, LS_INFO); |
| 151 | |
| 152 | RTC_LOG_IF(LS_INFO, true) << "Hello"; |
| 153 | EXPECT_NE(std::string::npos, str.find("Hello")); |
| 154 | |
| 155 | LogMessage::RemoveLogToStream(&stream); |
| 156 | } |
| 157 | |
| 158 | TEST(LogTest, LogIfDontLogIfConditionIsFalse) { |
| 159 | std::string str; |
| 160 | LogSinkImpl stream(&str); |
| 161 | LogMessage::AddLogToStream(&stream, LS_INFO); |
| 162 | |
| 163 | RTC_LOG_IF(LS_INFO, false) << "Hello"; |
| 164 | EXPECT_EQ(std::string::npos, str.find("Hello")); |
| 165 | |
| 166 | LogMessage::RemoveLogToStream(&stream); |
| 167 | } |
| 168 | |
| 169 | TEST(LogTest, LogIfFLogIfConditionIsTrue) { |
| 170 | std::string str; |
| 171 | LogSinkImpl stream(&str); |
| 172 | LogMessage::AddLogToStream(&stream, LS_INFO); |
| 173 | |
| 174 | RTC_LOG_IF_F(LS_INFO, true) << "Hello"; |
| 175 | EXPECT_NE(std::string::npos, str.find(__FUNCTION__)); |
| 176 | EXPECT_NE(std::string::npos, str.find("Hello")); |
| 177 | |
| 178 | LogMessage::RemoveLogToStream(&stream); |
| 179 | } |
| 180 | |
| 181 | TEST(LogTest, LogIfFDontLogIfConditionIsFalse) { |
| 182 | std::string str; |
| 183 | LogSinkImpl stream(&str); |
| 184 | LogMessage::AddLogToStream(&stream, LS_INFO); |
| 185 | |
| 186 | RTC_LOG_IF_F(LS_INFO, false) << "Not"; |
| 187 | EXPECT_EQ(std::string::npos, str.find(__FUNCTION__)); |
| 188 | EXPECT_EQ(std::string::npos, str.find("Not")); |
| 189 | |
| 190 | LogMessage::RemoveLogToStream(&stream); |
| 191 | } |
| 192 | |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 193 | // Test using multiple log streams. The INFO stream should get the INFO message, |
| 194 | // the VERBOSE stream should get the INFO and the VERBOSE. |
| 195 | // We should restore the correct global state at the end. |
| 196 | TEST(LogTest, MultipleStreams) { |
deadbeef | 37f5ecf | 2017-02-27 22:06:41 | [diff] [blame] | 197 | int sev = LogMessage::GetLogToStream(nullptr); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 198 | |
| 199 | std::string str1, str2; |
Niels Möller | ed3f9ec | 2021-03-29 10:12:29 | [diff] [blame] | 200 | LogSinkImpl stream1(&str1), stream2(&str2); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 201 | LogMessage::AddLogToStream(&stream1, LS_INFO); |
| 202 | LogMessage::AddLogToStream(&stream2, LS_VERBOSE); |
| 203 | EXPECT_EQ(LS_INFO, LogMessage::GetLogToStream(&stream1)); |
| 204 | EXPECT_EQ(LS_VERBOSE, LogMessage::GetLogToStream(&stream2)); |
| 205 | |
Mirko Bonadei | 675513b | 2017-11-09 10:09:25 | [diff] [blame] | 206 | RTC_LOG(LS_INFO) << "INFO"; |
| 207 | RTC_LOG(LS_VERBOSE) << "VERBOSE"; |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 208 | |
| 209 | EXPECT_NE(std::string::npos, str1.find("INFO")); |
| 210 | EXPECT_EQ(std::string::npos, str1.find("VERBOSE")); |
| 211 | EXPECT_NE(std::string::npos, str2.find("INFO")); |
| 212 | EXPECT_NE(std::string::npos, str2.find("VERBOSE")); |
| 213 | |
| 214 | LogMessage::RemoveLogToStream(&stream2); |
| 215 | LogMessage::RemoveLogToStream(&stream1); |
Tommi | 0eefb4d | 2015-05-23 07:54:07 | [diff] [blame] | 216 | EXPECT_EQ(LS_NONE, LogMessage::GetLogToStream(&stream2)); |
| 217 | EXPECT_EQ(LS_NONE, LogMessage::GetLogToStream(&stream1)); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 218 | |
deadbeef | 37f5ecf | 2017-02-27 22:06:41 | [diff] [blame] | 219 | EXPECT_EQ(sev, LogMessage::GetLogToStream(nullptr)); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 220 | } |
| 221 | |
Tommi | fef0500 | 2018-02-27 12:51:08 | [diff] [blame] | 222 | class LogThread { |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 223 | public: |
Markus Handell | ad5037b | 2021-05-07 13:02:36 | [diff] [blame] | 224 | void Start() { |
| 225 | thread_ = PlatformThread::SpawnJoinable( |
| 226 | [] { RTC_LOG(LS_VERBOSE) << "RTC_LOG"; }, "LogThread"); |
| 227 | } |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 228 | |
| 229 | private: |
Tommi | fef0500 | 2018-02-27 12:51:08 | [diff] [blame] | 230 | PlatformThread thread_; |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 231 | }; |
| 232 | |
Tommi | fef0500 | 2018-02-27 12:51:08 | [diff] [blame] | 233 | // Ensure we don't crash when adding/removing streams while threads are going. |
| 234 | // We should restore the correct global state at the end. |
henrike@webrtc.org | c732a3e | 2014-10-09 22:08:15 | [diff] [blame] | 235 | TEST(LogTest, MultipleThreads) { |
deadbeef | 37f5ecf | 2017-02-27 22:06:41 | [diff] [blame] | 236 | int sev = LogMessage::GetLogToStream(nullptr); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 237 | |
| 238 | LogThread thread1, thread2, thread3; |
| 239 | thread1.Start(); |
| 240 | thread2.Start(); |
| 241 | thread3.Start(); |
| 242 | |
Niels Möller | ff3dd0c | 2018-06-20 08:27:53 | [diff] [blame] | 243 | std::string s1, s2, s3; |
Niels Möller | ed3f9ec | 2021-03-29 10:12:29 | [diff] [blame] | 244 | LogSinkImpl stream1(&s1), stream2(&s2), stream3(&s3); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 245 | for (int i = 0; i < 1000; ++i) { |
Niels Möller | 25aefd3 | 2018-11-21 08:34:11 | [diff] [blame] | 246 | LogMessage::AddLogToStream(&stream1, LS_WARNING); |
| 247 | LogMessage::AddLogToStream(&stream2, LS_INFO); |
| 248 | LogMessage::AddLogToStream(&stream3, LS_VERBOSE); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 249 | LogMessage::RemoveLogToStream(&stream1); |
| 250 | LogMessage::RemoveLogToStream(&stream2); |
| 251 | LogMessage::RemoveLogToStream(&stream3); |
| 252 | } |
| 253 | |
deadbeef | 37f5ecf | 2017-02-27 22:06:41 | [diff] [blame] | 254 | EXPECT_EQ(sev, LogMessage::GetLogToStream(nullptr)); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 255 | } |
| 256 | |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 257 | TEST(LogTest, WallClockStartTime) { |
Peter Boström | 0c4e06b | 2015-10-07 10:23:21 | [diff] [blame] | 258 | uint32_t time = LogMessage::WallClockStartTime(); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 259 | // Expect the time to be in a sensible range, e.g. > 2012-01-01. |
| 260 | EXPECT_GT(time, 1325376000u); |
| 261 | } |
| 262 | |
Tommi | fef0500 | 2018-02-27 12:51:08 | [diff] [blame] | 263 | TEST(LogTest, CheckExtraErrorField) { |
Mirko Bonadei | 70ed471 | 2022-08-03 12:49:40 | [diff] [blame] | 264 | LogMessageForTesting log_msg(kFakeFilePath, 100, LS_WARNING, ERRCTX_ERRNO, |
| 265 | 0xD); |
Tommi | fef0500 | 2018-02-27 12:51:08 | [diff] [blame] | 266 | log_msg.stream() << "This gets added at dtor time"; |
phoglund | bb73873 | 2016-07-15 10:57:12 | [diff] [blame] | 267 | |
Tommi | fef0500 | 2018-02-27 12:51:08 | [diff] [blame] | 268 | const std::string& extra = log_msg.get_extra(); |
| 269 | const size_t length_to_check = arraysize("[0x12345678]") - 1; |
| 270 | ASSERT_GE(extra.length(), length_to_check); |
| 271 | EXPECT_EQ(std::string("[0x0000000D]"), extra.substr(0, length_to_check)); |
| 272 | } |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 273 | |
Tommi | fef0500 | 2018-02-27 12:51:08 | [diff] [blame] | 274 | TEST(LogTest, CheckFilePathParsed) { |
Mirko Bonadei | 96191f8 | 2022-08-03 08:12:33 | [diff] [blame] | 275 | std::string str; |
| 276 | LogSinkImpl stream(&str); |
| 277 | LogMessage::AddLogToStream(&stream, LS_INFO); |
| 278 | EXPECT_EQ(LS_INFO, LogMessage::GetLogToStream(&stream)); |
Paulina Hensman | f1e3cb4 | 2018-06-20 12:07:05 | [diff] [blame] | 279 | #if defined(WEBRTC_ANDROID) |
Mirko Bonadei | 96191f8 | 2022-08-03 08:12:33 | [diff] [blame] | 280 | const char* tag = nullptr; |
Paulina Hensman | f1e3cb4 | 2018-06-20 12:07:05 | [diff] [blame] | 281 | #endif |
Mirko Bonadei | 96191f8 | 2022-08-03 08:12:33 | [diff] [blame] | 282 | { |
Mirko Bonadei | 70ed471 | 2022-08-03 12:49:40 | [diff] [blame] | 283 | LogMessageForTesting log_msg(kFakeFilePath, 100, LS_INFO); |
Mirko Bonadei | 96191f8 | 2022-08-03 08:12:33 | [diff] [blame] | 284 | log_msg.stream() << "<- Does this look right?"; |
| 285 | #if defined(WEBRTC_ANDROID) |
| 286 | tag = log_msg.get_tag(); |
| 287 | #endif |
| 288 | } |
| 289 | |
| 290 | #if defined(WEBRTC_ANDROID) |
| 291 | EXPECT_NE(nullptr, strstr(tag, "myfile.cc")); |
| 292 | EXPECT_NE(std::string::npos, str.find("100")); |
| 293 | #else |
| 294 | EXPECT_NE(std::string::npos, str.find("(myfile.cc:100)")); |
| 295 | #endif |
| 296 | LogMessage::RemoveLogToStream(&stream); |
Tommi | fef0500 | 2018-02-27 12:51:08 | [diff] [blame] | 297 | } |
| 298 | |
Paulina Hensman | f1e3cb4 | 2018-06-20 12:07:05 | [diff] [blame] | 299 | #if defined(WEBRTC_ANDROID) |
| 300 | TEST(LogTest, CheckTagAddedToStringInDefaultOnLogMessageAndroid) { |
| 301 | std::string str; |
Niels Möller | ed3f9ec | 2021-03-29 10:12:29 | [diff] [blame] | 302 | LogSinkImpl stream(&str); |
Paulina Hensman | f1e3cb4 | 2018-06-20 12:07:05 | [diff] [blame] | 303 | LogMessage::AddLogToStream(&stream, LS_INFO); |
| 304 | EXPECT_EQ(LS_INFO, LogMessage::GetLogToStream(&stream)); |
| 305 | |
| 306 | RTC_LOG_TAG(LS_INFO, "my_tag") << "INFO"; |
| 307 | EXPECT_NE(std::string::npos, str.find("INFO")); |
| 308 | EXPECT_NE(std::string::npos, str.find("my_tag")); |
| 309 | } |
| 310 | #endif |
| 311 | |
Tommi | fef0500 | 2018-02-27 12:51:08 | [diff] [blame] | 312 | // Test the time required to write 1000 80-character logs to a string. |
| 313 | TEST(LogTest, Perf) { |
| 314 | std::string str; |
Niels Möller | ed3f9ec | 2021-03-29 10:12:29 | [diff] [blame] | 315 | LogSinkImpl stream(&str); |
Niels Möller | 25aefd3 | 2018-11-21 08:34:11 | [diff] [blame] | 316 | LogMessage::AddLogToStream(&stream, LS_VERBOSE); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 317 | |
Tommi | fef0500 | 2018-02-27 12:51:08 | [diff] [blame] | 318 | const std::string message(80, 'X'); |
Niels Möller | 25aefd3 | 2018-11-21 08:34:11 | [diff] [blame] | 319 | { LogMessageForTesting sanity_check_msg(__FILE__, __LINE__, LS_VERBOSE); } |
Tommi | fef0500 | 2018-02-27 12:51:08 | [diff] [blame] | 320 | |
| 321 | // We now know how many bytes the logging framework will tag onto every msg. |
| 322 | const size_t logging_overhead = str.size(); |
| 323 | // Reset the stream to 0 size. |
| 324 | str.clear(); |
| 325 | str.reserve(120000); |
| 326 | static const int kRepetitions = 1000; |
| 327 | |
Honghai Zhang | 82d7862 | 2016-05-06 18:29:15 | [diff] [blame] | 328 | int64_t start = TimeMillis(), finish; |
Tommi | fef0500 | 2018-02-27 12:51:08 | [diff] [blame] | 329 | for (int i = 0; i < kRepetitions; ++i) { |
Niels Möller | 25aefd3 | 2018-11-21 08:34:11 | [diff] [blame] | 330 | LogMessageForTesting(__FILE__, __LINE__, LS_VERBOSE).stream() << message; |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 331 | } |
Honghai Zhang | 82d7862 | 2016-05-06 18:29:15 | [diff] [blame] | 332 | finish = TimeMillis(); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 333 | |
| 334 | LogMessage::RemoveLogToStream(&stream); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 335 | |
Tommi | fef0500 | 2018-02-27 12:51:08 | [diff] [blame] | 336 | EXPECT_EQ(str.size(), (message.size() + logging_overhead) * kRepetitions); |
Jonas Olsson | b2b2031 | 2020-01-14 11:11:31 | [diff] [blame] | 337 | RTC_LOG(LS_INFO) << "Total log time: " << TimeDiff(finish, start) |
| 338 | << " ms " |
| 339 | " total bytes logged: " |
| 340 | << str.size(); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 341 | } |
| 342 | |
Amit Hilbuch | 10c5a93 | 2019-03-18 20:09:18 | [diff] [blame] | 343 | TEST(LogTest, EnumsAreSupported) { |
| 344 | enum class TestEnum { kValue0 = 0, kValue1 = 1 }; |
| 345 | std::string str; |
Niels Möller | ed3f9ec | 2021-03-29 10:12:29 | [diff] [blame] | 346 | LogSinkImpl stream(&str); |
Amit Hilbuch | 10c5a93 | 2019-03-18 20:09:18 | [diff] [blame] | 347 | LogMessage::AddLogToStream(&stream, LS_INFO); |
| 348 | RTC_LOG(LS_INFO) << "[" << TestEnum::kValue0 << "]"; |
| 349 | EXPECT_NE(std::string::npos, str.find("[0]")); |
| 350 | EXPECT_EQ(std::string::npos, str.find("[1]")); |
| 351 | RTC_LOG(LS_INFO) << "[" << TestEnum::kValue1 << "]"; |
| 352 | EXPECT_NE(std::string::npos, str.find("[1]")); |
| 353 | LogMessage::RemoveLogToStream(&stream); |
Amit Hilbuch | 10c5a93 | 2019-03-18 20:09:18 | [diff] [blame] | 354 | } |
| 355 | |
Tomas Gunnarsson | edd7f9e | 2020-09-21 14:44:55 | [diff] [blame] | 356 | TEST(LogTest, NoopSeverityDoesNotRunStringFormatting) { |
| 357 | if (!LogMessage::IsNoop(LS_VERBOSE)) { |
| 358 | RTC_LOG(LS_WARNING) << "Skipping test since verbose logging is turned on."; |
| 359 | return; |
| 360 | } |
| 361 | bool was_called = false; |
| 362 | auto cb = [&was_called]() { |
| 363 | was_called = true; |
| 364 | return "This could be an expensive callback."; |
| 365 | }; |
| 366 | RTC_LOG(LS_VERBOSE) << "This should not be logged: " << cb(); |
| 367 | EXPECT_FALSE(was_called); |
| 368 | } |
| 369 | |
Evan Shrubsole | 7765f9e | 2022-04-25 09:04:12 | [diff] [blame] | 370 | struct TestStruct {}; |
| 371 | std::string ToLogString(TestStruct foo) { |
| 372 | return "bar"; |
| 373 | } |
| 374 | |
| 375 | TEST(LogTest, ToLogStringUsedForUnknownTypes) { |
| 376 | std::string str; |
| 377 | LogSinkImpl stream(&str); |
| 378 | LogMessage::AddLogToStream(&stream, LS_INFO); |
| 379 | TestStruct t; |
| 380 | RTC_LOG(LS_INFO) << t; |
| 381 | EXPECT_THAT(str, ::testing::HasSubstr("bar")); |
| 382 | LogMessage::RemoveLogToStream(&stream); |
| 383 | } |
| 384 | |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 385 | } // namespace rtc |
Tomas Gunnarsson | edd7f9e | 2020-09-21 14:44:55 | [diff] [blame] | 386 | #endif // RTC_LOG_ENABLED() |