device_event_log_impl_unittest.cc 13 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368
  1. // Copyright 2014 The Chromium Authors. All rights reserved.
  2. // Use of this source code is governed by a BSD-style license that can be
  3. // found in the LICENSE file.
  4. #include "components/device_event_log/device_event_log_impl.h"
  5. #include <stddef.h>
  6. #include <algorithm>
  7. #include <memory>
  8. #include <string>
  9. #include "base/bind.h"
  10. #include "base/compiler_specific.h"
  11. #include "base/format_macros.h"
  12. #include "base/strings/string_split.h"
  13. #include "base/strings/stringprintf.h"
  14. #include "base/test/test_simple_task_runner.h"
  15. #include "base/time/time.h"
  16. #include "build/build_config.h"
  17. #include "testing/gtest/include/gtest/gtest.h"
  18. namespace device_event_log {
  19. namespace {
  20. const size_t kDefaultMaxEvents = 100;
  21. LogLevel kDefaultLevel = LOG_LEVEL_EVENT;
  22. LogType kDefaultType = LOG_TYPE_NETWORK;
  23. const char kFileName[] = "file";
  24. // Calls GetAsString on the task thread and sets s_string_result. Make sure
  25. // that task_runner_->RunUntilIdle() is called before using s_string_result.
  26. std::string s_string_result;
  27. void CallGetAsString(DeviceEventLogImpl* impl,
  28. StringOrder order,
  29. const std::string& format,
  30. const std::string& types,
  31. LogLevel max_level,
  32. size_t max_events) {
  33. s_string_result =
  34. impl->GetAsString(order, format, types, max_level, max_events);
  35. }
  36. } // namespace
  37. class DeviceEventLogTest : public testing::Test {
  38. public:
  39. DeviceEventLogTest() : task_runner_(new base::TestSimpleTaskRunner()) {}
  40. DeviceEventLogTest(const DeviceEventLogTest&) = delete;
  41. DeviceEventLogTest& operator=(const DeviceEventLogTest&) = delete;
  42. void SetUp() override {
  43. impl_ =
  44. std::make_unique<DeviceEventLogImpl>(task_runner_, kDefaultMaxEvents);
  45. }
  46. void TearDown() override { impl_.reset(); }
  47. protected:
  48. std::string SkipTime(const std::string& input) {
  49. std::string output;
  50. for (const std::string& line : base::SplitString(
  51. input, "\n", base::TRIM_WHITESPACE, base::SPLIT_WANT_ALL)) {
  52. size_t n = line.find(']');
  53. if (n != std::string::npos)
  54. output += "[time] " + line.substr(n + 2) + '\n';
  55. else
  56. output += line;
  57. }
  58. return output;
  59. }
  60. size_t CountLines(const std::string& input) {
  61. return std::count(input.begin(), input.end(), '\n');
  62. }
  63. std::string GetAsString(StringOrder order,
  64. const std::string& format,
  65. const std::string& types,
  66. LogLevel max_level,
  67. size_t max_events) {
  68. task_runner_->PostTask(
  69. FROM_HERE, base::BindOnce(&CallGetAsString, impl_.get(), order, format,
  70. types, max_level, max_events));
  71. task_runner_->RunUntilIdle();
  72. return s_string_result;
  73. }
  74. std::string GetLogString(StringOrder order,
  75. const std::string& format,
  76. LogLevel max_level,
  77. size_t max_events) {
  78. return GetAsString(order, format, "", max_level, max_events);
  79. }
  80. std::string GetOrderedString(StringOrder order, size_t max_events) {
  81. return GetAsString(order, "file", "", kDefaultLevel, max_events);
  82. }
  83. std::string GetLogStringForType(const std::string& types) {
  84. return GetAsString(OLDEST_FIRST, "type", types, kDefaultLevel, 0);
  85. }
  86. void AddNetworkEntry(const char* file,
  87. int line,
  88. LogLevel level,
  89. const std::string& event) {
  90. impl_->AddEntry(file, line, kDefaultType, level, event);
  91. task_runner_->RunUntilIdle();
  92. }
  93. void AddTestEvent(LogLevel level, const std::string& event) {
  94. AddNetworkEntry(kFileName, 0, level, event);
  95. }
  96. void AddTestEventWithTimestamp(LogLevel level,
  97. const std::string& event,
  98. base::Time time) {
  99. impl_->AddEntryWithTimestampForTesting(kFileName, 0, kDefaultType, level,
  100. event, time);
  101. task_runner_->RunUntilIdle();
  102. }
  103. void AddEventType(LogType type, const std::string& event) {
  104. impl_->AddEntry(kFileName, 0, type, kDefaultLevel, event);
  105. task_runner_->RunUntilIdle();
  106. }
  107. size_t GetMaxEntries() const { return impl_->max_entries(); }
  108. scoped_refptr<base::TestSimpleTaskRunner> task_runner_;
  109. std::unique_ptr<DeviceEventLogImpl> impl_;
  110. };
  111. TEST_F(DeviceEventLogTest, TestNetworkEvents) {
  112. std::string output_none = GetOrderedString(OLDEST_FIRST, 0);
  113. EXPECT_EQ("No Log Entries.", output_none);
  114. LogLevel level = kDefaultLevel;
  115. static const char kFile1[] = "file1";
  116. static const char kFile2[] = "file2";
  117. static const char kFile3[] = "file3";
  118. AddNetworkEntry(kFile1, 1, level, "event1");
  119. AddNetworkEntry(kFile2, 2, level, "event2");
  120. AddNetworkEntry(kFile3, 3, level, "event3");
  121. AddNetworkEntry(kFile3, 3, level, "event3");
  122. const std::string expected_output_oldest_first(
  123. "file1:1 event1\n"
  124. "file2:2 event2\n"
  125. "file3:3 event3 (2)\n");
  126. std::string output_oldest_first = GetOrderedString(OLDEST_FIRST, 0);
  127. EXPECT_EQ(expected_output_oldest_first, output_oldest_first);
  128. const std::string expected_output_oldest_first_short(
  129. "file2:2 event2\n"
  130. "file3:3 event3 (2)\n");
  131. std::string output_oldest_first_short = GetOrderedString(OLDEST_FIRST, 2);
  132. EXPECT_EQ(expected_output_oldest_first_short, output_oldest_first_short);
  133. const std::string expected_output_newest_first(
  134. "file3:3 event3 (2)\n"
  135. "file2:2 event2\n"
  136. "file1:1 event1\n");
  137. std::string output_newest_first = GetOrderedString(NEWEST_FIRST, 0);
  138. EXPECT_EQ(expected_output_newest_first, output_newest_first);
  139. const std::string expected_output_newest_first_short(
  140. "file3:3 event3 (2)\n"
  141. "file2:2 event2\n");
  142. std::string output_newest_first_short = GetOrderedString(NEWEST_FIRST, 2);
  143. EXPECT_EQ(expected_output_newest_first_short, output_newest_first_short);
  144. }
  145. TEST_F(DeviceEventLogTest, TestMaxEntries) {
  146. const size_t max_entries = GetMaxEntries();
  147. const size_t entries_to_add = max_entries + 3;
  148. for (size_t i = 0; i < entries_to_add; ++i) {
  149. AddTestEvent(LOG_LEVEL_EVENT, base::StringPrintf("event_%" PRIuS, i));
  150. }
  151. std::string output = GetOrderedString(OLDEST_FIRST, 0);
  152. size_t output_lines = CountLines(output);
  153. EXPECT_EQ(max_entries, output_lines);
  154. }
  155. TEST_F(DeviceEventLogTest, TestStringFormat) {
  156. AddTestEvent(LOG_LEVEL_ERROR, "event0");
  157. EXPECT_EQ("file:0 event0\n",
  158. GetLogString(OLDEST_FIRST, "file", kDefaultLevel, 1));
  159. EXPECT_EQ("[time] event0\n",
  160. SkipTime(GetLogString(OLDEST_FIRST, "time", kDefaultLevel, 1)));
  161. EXPECT_EQ("event0\n", GetLogString(OLDEST_FIRST, "", kDefaultLevel, 1));
  162. EXPECT_EQ(
  163. "[time] file:0 event0\n",
  164. SkipTime(GetLogString(OLDEST_FIRST, "file,time", kDefaultLevel, 1)));
  165. AddTestEvent(LOG_LEVEL_DEBUG, "event1");
  166. AddTestEvent(kDefaultLevel, "event2");
  167. EXPECT_EQ("Network: file:0 event2\n",
  168. GetLogString(OLDEST_FIRST, "file,type", kDefaultLevel, 1));
  169. }
  170. TEST_F(DeviceEventLogTest, TestTimeFormat) {
  171. const int hour = 12;
  172. const std::string time_str = base::StringPrintf("1 Jan 2020 %d:34:56", hour);
  173. base::Time time;
  174. ASSERT_TRUE(base::Time::FromUTCString(time_str.c_str(), &time));
  175. base::Time::Exploded exploded;
  176. // This gets the offset for the current system time, which is what will be
  177. // used in the logs. TODO(stevenjb): Figure out a more robust test mechanism.
  178. // Using base::test::ScopedRestoreDefaultTimezone does not work as expected.
  179. time.LocalExplode(&exploded);
  180. int hour_delta = exploded.hour - hour;
  181. AddTestEventWithTimestamp(LOG_LEVEL_EVENT, "event0", time);
  182. std::string extected_time_str =
  183. base::StringPrintf("%02d:34:56.000", hour + hour_delta);
  184. EXPECT_EQ(base::StringPrintf("[%s] event0\n", extected_time_str.c_str()),
  185. GetLogString(OLDEST_FIRST, "time", kDefaultLevel, 1));
  186. #if BUILDFLAG(IS_POSIX)
  187. char sign = hour_delta > 0 ? '+' : '-';
  188. std::string expected_time =
  189. base::StringPrintf("2020-01-01T%02d:34:56.000000%c%02d:00",
  190. hour + hour_delta, sign, std::abs(hour_delta));
  191. EXPECT_EQ(base::StringPrintf("%s event0\n", expected_time.c_str()),
  192. GetLogString(OLDEST_FIRST, "unixtime", kDefaultLevel, 1));
  193. #endif
  194. }
  195. TEST_F(DeviceEventLogTest, TestLogLevel) {
  196. AddTestEvent(LOG_LEVEL_ERROR, "error1");
  197. AddTestEvent(LOG_LEVEL_ERROR, "error2");
  198. AddTestEvent(LOG_LEVEL_EVENT, "event3");
  199. AddTestEvent(LOG_LEVEL_ERROR, "error4");
  200. AddTestEvent(LOG_LEVEL_EVENT, "event5");
  201. AddTestEvent(LOG_LEVEL_DEBUG, "debug6");
  202. std::string out;
  203. out = GetLogString(OLDEST_FIRST, "", LOG_LEVEL_ERROR, 0);
  204. EXPECT_EQ(3u, CountLines(out));
  205. out = GetLogString(OLDEST_FIRST, "", LOG_LEVEL_EVENT, 0);
  206. EXPECT_EQ(5u, CountLines(out));
  207. out = GetLogString(OLDEST_FIRST, "", LOG_LEVEL_DEBUG, 0);
  208. EXPECT_EQ(6u, CountLines(out));
  209. // Test max_level. Get only the ERROR entries.
  210. out = GetLogString(OLDEST_FIRST, "", LOG_LEVEL_ERROR, 0);
  211. EXPECT_EQ("error1\nerror2\nerror4\n", out);
  212. }
  213. TEST_F(DeviceEventLogTest, TestMaxEvents) {
  214. AddTestEvent(LOG_LEVEL_EVENT, "event1");
  215. AddTestEvent(LOG_LEVEL_ERROR, "error2");
  216. AddTestEvent(LOG_LEVEL_EVENT, "event3");
  217. AddTestEvent(LOG_LEVEL_ERROR, "error4");
  218. AddTestEvent(LOG_LEVEL_EVENT, "event5");
  219. // Oldest first
  220. EXPECT_EQ("error4\n", GetLogString(OLDEST_FIRST, "", LOG_LEVEL_ERROR, 1));
  221. EXPECT_EQ("error2\nerror4\n",
  222. GetLogString(OLDEST_FIRST, "", LOG_LEVEL_ERROR, 2));
  223. EXPECT_EQ("event3\nerror4\nevent5\n",
  224. GetLogString(OLDEST_FIRST, "", LOG_LEVEL_EVENT, 3));
  225. EXPECT_EQ("error2\nevent3\nerror4\nevent5\n",
  226. GetLogString(OLDEST_FIRST, "", LOG_LEVEL_EVENT, 4));
  227. EXPECT_EQ("event1\nerror2\nevent3\nerror4\nevent5\n",
  228. GetLogString(OLDEST_FIRST, "", LOG_LEVEL_EVENT, 5));
  229. // Newest first
  230. EXPECT_EQ("error4\n", GetLogString(NEWEST_FIRST, "", LOG_LEVEL_ERROR, 1));
  231. EXPECT_EQ("error4\nerror2\n",
  232. GetLogString(NEWEST_FIRST, "", LOG_LEVEL_ERROR, 2));
  233. EXPECT_EQ("event5\nerror4\nevent3\n",
  234. GetLogString(NEWEST_FIRST, "", LOG_LEVEL_EVENT, 3));
  235. EXPECT_EQ("event5\nerror4\nevent3\nerror2\n",
  236. GetLogString(NEWEST_FIRST, "", LOG_LEVEL_EVENT, 4));
  237. EXPECT_EQ("event5\nerror4\nevent3\nerror2\nevent1\n",
  238. GetLogString(NEWEST_FIRST, "", LOG_LEVEL_EVENT, 5));
  239. }
  240. TEST_F(DeviceEventLogTest, TestMaxErrors) {
  241. const int kMaxTestEntries = 4;
  242. impl_ = std::make_unique<DeviceEventLogImpl>(task_runner_, kMaxTestEntries);
  243. AddTestEvent(LOG_LEVEL_EVENT, "event1");
  244. AddTestEvent(LOG_LEVEL_ERROR, "error2");
  245. AddTestEvent(LOG_LEVEL_EVENT, "event3");
  246. AddTestEvent(LOG_LEVEL_ERROR, "error4");
  247. AddTestEvent(LOG_LEVEL_EVENT, "event5");
  248. AddTestEvent(LOG_LEVEL_EVENT, "event6");
  249. EXPECT_EQ("error2\nerror4\nevent5\nevent6\n",
  250. GetLogString(OLDEST_FIRST, "", LOG_LEVEL_DEBUG, 0));
  251. }
  252. TEST_F(DeviceEventLogTest, TestType) {
  253. AddEventType(LOG_TYPE_NETWORK, "event1");
  254. AddEventType(LOG_TYPE_POWER, "event2");
  255. AddEventType(LOG_TYPE_NETWORK, "event3");
  256. AddEventType(LOG_TYPE_POWER, "event4");
  257. AddEventType(LOG_TYPE_NETWORK, "event5");
  258. AddEventType(LOG_TYPE_NETWORK, "event6");
  259. EXPECT_EQ(
  260. "Network: event1\nNetwork: event3\nNetwork: event5\nNetwork: event6\n",
  261. GetLogStringForType("network"));
  262. const std::string power_events("Power: event2\nPower: event4\n");
  263. EXPECT_EQ(power_events, GetLogStringForType("power"));
  264. EXPECT_EQ(power_events, GetLogStringForType("non-network"));
  265. const std::string all_events(
  266. "Network: event1\n"
  267. "Power: event2\n"
  268. "Network: event3\n"
  269. "Power: event4\n"
  270. "Network: event5\n"
  271. "Network: event6\n");
  272. EXPECT_EQ(all_events, GetLogStringForType("network,power"));
  273. EXPECT_EQ(all_events, GetLogStringForType(""));
  274. }
  275. TEST_F(DeviceEventLogTest, TestClear) {
  276. AddTestEvent(LOG_LEVEL_EVENT, "event1");
  277. AddTestEvent(LOG_LEVEL_EVENT, "event2");
  278. AddTestEvent(LOG_LEVEL_EVENT, "event3");
  279. AddTestEvent(LOG_LEVEL_EVENT, "event4");
  280. std::string out = GetLogString(OLDEST_FIRST, "", LOG_LEVEL_EVENT, 0);
  281. EXPECT_EQ(4u, CountLines(out));
  282. impl_->Clear(base::Time(), base::Time::Max());
  283. out = GetLogString(OLDEST_FIRST, "", LOG_LEVEL_EVENT, 0);
  284. EXPECT_EQ(0u, CountLines(out));
  285. }
  286. TEST_F(DeviceEventLogTest, TestClearRange) {
  287. AddTestEventWithTimestamp(LOG_LEVEL_EVENT, "event1",
  288. base::Time() + base::Seconds(1));
  289. AddTestEventWithTimestamp(LOG_LEVEL_EVENT, "event2",
  290. base::Time() + base::Seconds(2));
  291. AddTestEventWithTimestamp(LOG_LEVEL_EVENT, "event3",
  292. base::Time() + base::Seconds(3));
  293. AddTestEventWithTimestamp(LOG_LEVEL_EVENT, "event4",
  294. base::Time() + base::Seconds(4));
  295. EXPECT_EQ("event1\nevent2\nevent3\nevent4\n",
  296. GetLogString(OLDEST_FIRST, "", LOG_LEVEL_EVENT, 0));
  297. impl_->Clear(base::Time() + base::Seconds(2),
  298. base::Time() + base::Seconds(3));
  299. EXPECT_EQ("event1\nevent4\n",
  300. GetLogString(OLDEST_FIRST, "", LOG_LEVEL_EVENT, 0));
  301. }
  302. } // namespace device_event_log