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 | |
| 11 | #include "webrtc/base/fileutils.h" |
| 12 | #include "webrtc/base/gunit.h" |
| 13 | #include "webrtc/base/logging.h" |
| 14 | #include "webrtc/base/pathutils.h" |
| 15 | #include "webrtc/base/stream.h" |
| 16 | #include "webrtc/base/thread.h" |
| 17 | |
| 18 | namespace rtc { |
| 19 | |
Tommi | 0eefb4d | 2015-05-23 07:54:07 | [diff] [blame] | 20 | template <typename Base> |
| 21 | class LogSinkImpl |
| 22 | : public LogSink, |
| 23 | public Base { |
| 24 | public: |
| 25 | LogSinkImpl() {} |
| 26 | |
Tommi | 0eefb4d | 2015-05-23 07:54:07 | [diff] [blame] | 27 | template<typename P> |
Tommi | 00aac5a | 2015-05-25 09:25:59 | [diff] [blame] | 28 | explicit LogSinkImpl(P* p) : Base(p) {} |
Tommi | 0eefb4d | 2015-05-23 07:54:07 | [diff] [blame] | 29 | |
| 30 | private: |
| 31 | void OnLogMessage(const std::string& message) override { |
| 32 | static_cast<Base*>(this)->WriteAll( |
| 33 | message.data(), message.size(), nullptr, nullptr); |
| 34 | } |
| 35 | }; |
| 36 | |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 37 | // Test basic logging operation. We should get the INFO log but not the VERBOSE. |
| 38 | // We should restore the correct global state at the end. |
| 39 | TEST(LogTest, SingleStream) { |
| 40 | int sev = LogMessage::GetLogToStream(NULL); |
| 41 | |
| 42 | std::string str; |
Tommi | 00aac5a | 2015-05-25 09:25:59 | [diff] [blame] | 43 | LogSinkImpl<StringStream> stream(&str); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 44 | LogMessage::AddLogToStream(&stream, LS_INFO); |
| 45 | EXPECT_EQ(LS_INFO, LogMessage::GetLogToStream(&stream)); |
| 46 | |
| 47 | LOG(LS_INFO) << "INFO"; |
| 48 | LOG(LS_VERBOSE) << "VERBOSE"; |
| 49 | EXPECT_NE(std::string::npos, str.find("INFO")); |
| 50 | EXPECT_EQ(std::string::npos, str.find("VERBOSE")); |
| 51 | |
| 52 | LogMessage::RemoveLogToStream(&stream); |
Tommi | 0eefb4d | 2015-05-23 07:54:07 | [diff] [blame] | 53 | EXPECT_EQ(LS_NONE, LogMessage::GetLogToStream(&stream)); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 54 | |
| 55 | EXPECT_EQ(sev, LogMessage::GetLogToStream(NULL)); |
| 56 | } |
| 57 | |
| 58 | // Test using multiple log streams. The INFO stream should get the INFO message, |
| 59 | // the VERBOSE stream should get the INFO and the VERBOSE. |
| 60 | // We should restore the correct global state at the end. |
| 61 | TEST(LogTest, MultipleStreams) { |
| 62 | int sev = LogMessage::GetLogToStream(NULL); |
| 63 | |
| 64 | std::string str1, str2; |
Tommi | 00aac5a | 2015-05-25 09:25:59 | [diff] [blame] | 65 | LogSinkImpl<StringStream> stream1(&str1), stream2(&str2); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 66 | LogMessage::AddLogToStream(&stream1, LS_INFO); |
| 67 | LogMessage::AddLogToStream(&stream2, LS_VERBOSE); |
| 68 | EXPECT_EQ(LS_INFO, LogMessage::GetLogToStream(&stream1)); |
| 69 | EXPECT_EQ(LS_VERBOSE, LogMessage::GetLogToStream(&stream2)); |
| 70 | |
| 71 | LOG(LS_INFO) << "INFO"; |
| 72 | LOG(LS_VERBOSE) << "VERBOSE"; |
| 73 | |
| 74 | EXPECT_NE(std::string::npos, str1.find("INFO")); |
| 75 | EXPECT_EQ(std::string::npos, str1.find("VERBOSE")); |
| 76 | EXPECT_NE(std::string::npos, str2.find("INFO")); |
| 77 | EXPECT_NE(std::string::npos, str2.find("VERBOSE")); |
| 78 | |
| 79 | LogMessage::RemoveLogToStream(&stream2); |
| 80 | LogMessage::RemoveLogToStream(&stream1); |
Tommi | 0eefb4d | 2015-05-23 07:54:07 | [diff] [blame] | 81 | EXPECT_EQ(LS_NONE, LogMessage::GetLogToStream(&stream2)); |
| 82 | EXPECT_EQ(LS_NONE, LogMessage::GetLogToStream(&stream1)); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 83 | |
| 84 | EXPECT_EQ(sev, LogMessage::GetLogToStream(NULL)); |
| 85 | } |
| 86 | |
| 87 | // Ensure we don't crash when adding/removing streams while threads are going. |
| 88 | // We should restore the correct global state at the end. |
| 89 | class LogThread : public Thread { |
| 90 | public: |
| 91 | virtual ~LogThread() { |
| 92 | Stop(); |
| 93 | } |
| 94 | |
| 95 | private: |
| 96 | void Run() { |
| 97 | // LS_SENSITIVE to avoid cluttering up any real logging going on |
| 98 | LOG(LS_SENSITIVE) << "LOG"; |
| 99 | } |
| 100 | }; |
| 101 | |
henrike@webrtc.org | c732a3e | 2014-10-09 22:08:15 | [diff] [blame] | 102 | TEST(LogTest, MultipleThreads) { |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 103 | int sev = LogMessage::GetLogToStream(NULL); |
| 104 | |
| 105 | LogThread thread1, thread2, thread3; |
| 106 | thread1.Start(); |
| 107 | thread2.Start(); |
| 108 | thread3.Start(); |
| 109 | |
Tommi | 0eefb4d | 2015-05-23 07:54:07 | [diff] [blame] | 110 | LogSinkImpl<NullStream> stream1, stream2, stream3; |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 111 | for (int i = 0; i < 1000; ++i) { |
| 112 | LogMessage::AddLogToStream(&stream1, LS_INFO); |
| 113 | LogMessage::AddLogToStream(&stream2, LS_VERBOSE); |
| 114 | LogMessage::AddLogToStream(&stream3, LS_SENSITIVE); |
| 115 | LogMessage::RemoveLogToStream(&stream1); |
| 116 | LogMessage::RemoveLogToStream(&stream2); |
| 117 | LogMessage::RemoveLogToStream(&stream3); |
| 118 | } |
| 119 | |
| 120 | EXPECT_EQ(sev, LogMessage::GetLogToStream(NULL)); |
| 121 | } |
| 122 | |
| 123 | |
| 124 | TEST(LogTest, WallClockStartTime) { |
Peter Boström | 0c4e06b | 2015-10-07 10:23:21 | [diff] [blame] | 125 | uint32_t time = LogMessage::WallClockStartTime(); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 126 | // Expect the time to be in a sensible range, e.g. > 2012-01-01. |
| 127 | EXPECT_GT(time, 1325376000u); |
| 128 | } |
| 129 | |
| 130 | // Test the time required to write 1000 80-character logs to an unbuffered file. |
| 131 | TEST(LogTest, Perf) { |
| 132 | Pathname path; |
| 133 | EXPECT_TRUE(Filesystem::GetTemporaryFolder(path, true, NULL)); |
| 134 | path.SetPathname(Filesystem::TempFilename(path, "ut")); |
| 135 | |
Tommi | 0eefb4d | 2015-05-23 07:54:07 | [diff] [blame] | 136 | LogSinkImpl<FileStream> stream; |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 137 | EXPECT_TRUE(stream.Open(path.pathname(), "wb", NULL)); |
| 138 | stream.DisableBuffering(); |
| 139 | LogMessage::AddLogToStream(&stream, LS_SENSITIVE); |
| 140 | |
Honghai Zhang | 82d7862 | 2016-05-06 18:29:15 | [diff] [blame] | 141 | int64_t start = TimeMillis(), finish; |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 142 | std::string message('X', 80); |
| 143 | for (int i = 0; i < 1000; ++i) { |
| 144 | LOG(LS_SENSITIVE) << message; |
| 145 | } |
Honghai Zhang | 82d7862 | 2016-05-06 18:29:15 | [diff] [blame] | 146 | finish = TimeMillis(); |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 147 | |
| 148 | LogMessage::RemoveLogToStream(&stream); |
| 149 | stream.Close(); |
| 150 | Filesystem::DeleteFile(path); |
| 151 | |
Honghai Zhang | 82d7862 | 2016-05-06 18:29:15 | [diff] [blame] | 152 | LOG(LS_INFO) << "Average log time: " << TimeDiff(finish, start) << " ms"; |
henrike@webrtc.org | f048872 | 2014-05-13 18:00:26 | [diff] [blame] | 153 | } |
| 154 | |
| 155 | } // namespace rtc |