net_log_proxy_source_unittest.cc 13 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326
  1. // Copyright 2020 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/net_log/net_log_proxy_source.h"
  5. #include "base/run_loop.h"
  6. #include "base/synchronization/lock.h"
  7. #include "base/task/thread_pool.h"
  8. #include "base/test/bind.h"
  9. #include "base/test/task_environment.h"
  10. #include "base/time/time.h"
  11. #include "net/log/net_log.h"
  12. #include "net/log/net_log_with_source.h"
  13. #include "testing/gtest/include/gtest/gtest.h"
  14. namespace {
  15. class FakeNetLogProxySink : public network::mojom::NetLogProxySink {
  16. public:
  17. FakeNetLogProxySink(mojo::PendingReceiver<network::mojom::NetLogProxySink>
  18. proxy_sink_receiver,
  19. int expected_number_of_events)
  20. : proxy_sink_receiver_(this, std::move(proxy_sink_receiver)),
  21. run_loop_quit_after_count_(expected_number_of_events) {}
  22. FakeNetLogProxySink(const FakeNetLogProxySink&) = delete;
  23. FakeNetLogProxySink& operator=(const FakeNetLogProxySink&) = delete;
  24. struct ProxiedEntry {
  25. ProxiedEntry(uint32_t type,
  26. uint32_t source_type,
  27. uint32_t source_id,
  28. base::TimeTicks source_start_time,
  29. net::NetLogEventPhase phase,
  30. base::TimeTicks time,
  31. base::Value params)
  32. : type(type),
  33. source_type(source_type),
  34. source_id(source_id),
  35. source_start_time(source_start_time),
  36. phase(phase),
  37. time(time),
  38. params(std::move(params)) {}
  39. ProxiedEntry(const ProxiedEntry& other)
  40. : ProxiedEntry(other.type,
  41. other.source_type,
  42. other.source_id,
  43. other.source_start_time,
  44. other.phase,
  45. other.time,
  46. other.params.Clone()) {}
  47. uint32_t type;
  48. uint32_t source_type;
  49. uint32_t source_id;
  50. base::TimeTicks source_start_time;
  51. net::NetLogEventPhase phase;
  52. base::TimeTicks time;
  53. base::Value params;
  54. };
  55. std::vector<ProxiedEntry> entries() const {
  56. base::AutoLock lock(lock_);
  57. return entries_;
  58. }
  59. void WaitForExpectedEntries() { run_loop_.Run(); }
  60. // mojom::NetLogProxySink:
  61. void AddEntry(uint32_t type,
  62. uint32_t source_type,
  63. uint32_t source_id,
  64. base::TimeTicks source_start_time,
  65. net::NetLogEventPhase phase,
  66. base::TimeTicks time,
  67. base::Value params) override {
  68. base::AutoLock lock(lock_);
  69. entries_.emplace_back(type, source_type, source_id, source_start_time,
  70. phase, time, std::move(params));
  71. run_loop_quit_after_count_--;
  72. EXPECT_LE(0, run_loop_quit_after_count_);
  73. if (run_loop_quit_after_count_ == 0)
  74. run_loop_.Quit();
  75. }
  76. private:
  77. mutable base::Lock lock_;
  78. std::vector<ProxiedEntry> entries_;
  79. mojo::Receiver<network::mojom::NetLogProxySink> proxy_sink_receiver_;
  80. int run_loop_quit_after_count_;
  81. base::RunLoop run_loop_;
  82. };
  83. class NetLogCaptureModeWaiter
  84. : public net::NetLog::ThreadSafeCaptureModeObserver {
  85. public:
  86. explicit NetLogCaptureModeWaiter(
  87. const std::vector<net::NetLogCaptureModeSet>& expected_modes)
  88. : expected_modes_(expected_modes) {
  89. net::NetLog::Get()->AddCaptureModeObserver(this);
  90. }
  91. ~NetLogCaptureModeWaiter() override {
  92. net::NetLog::Get()->RemoveCaptureModeObserver(this);
  93. }
  94. void WaitForCaptureModeUpdate() { run_loop_.Run(); }
  95. // net::NetLog::ThreadSafeCaptureModeObserver:
  96. void OnCaptureModeUpdated(net::NetLogCaptureModeSet modes) override {
  97. ASSERT_FALSE(expected_modes_.empty())
  98. << "NetLogCaptureModeWaiter called too many times, modes = " << modes;
  99. EXPECT_EQ(expected_modes_.front(), modes);
  100. expected_modes_.erase(expected_modes_.begin());
  101. if (expected_modes_.empty())
  102. run_loop_.Quit();
  103. }
  104. private:
  105. std::vector<net::NetLogCaptureModeSet> expected_modes_;
  106. base::RunLoop run_loop_;
  107. };
  108. base::Value NetLogCaptureModeToParams(net::NetLogCaptureMode capture_mode) {
  109. base::Value dict(base::Value::Type::DICTIONARY);
  110. switch (capture_mode) {
  111. case net::NetLogCaptureMode::kDefault:
  112. dict.SetStringKey("capture_mode", "kDefault");
  113. break;
  114. case net::NetLogCaptureMode::kIncludeSensitive:
  115. dict.SetStringKey("capture_mode", "kIncludeSensitive");
  116. break;
  117. case net::NetLogCaptureMode::kEverything:
  118. dict.SetStringKey("capture_mode", "kEverything");
  119. break;
  120. }
  121. return dict;
  122. }
  123. } // namespace
  124. TEST(NetLogProxySource, OnlyProxiesEventsWhenCaptureModeSetIsNonZero) {
  125. base::test::TaskEnvironment task_environment{
  126. base::test::TaskEnvironment::TimeSource::MOCK_TIME};
  127. const size_t kExpectedEventCount = 2;
  128. mojo::Remote<network::mojom::NetLogProxySource> proxy_source_remote;
  129. mojo::Remote<network::mojom::NetLogProxySink> proxy_sink_remote;
  130. FakeNetLogProxySink sink(proxy_sink_remote.BindNewPipeAndPassReceiver(),
  131. kExpectedEventCount);
  132. net_log::NetLogProxySource net_log_source(
  133. proxy_source_remote.BindNewPipeAndPassReceiver(),
  134. std::move(proxy_sink_remote));
  135. // No capture modes are set, so should not get proxied.
  136. task_environment.FastForwardBy(base::Seconds(9876));
  137. net::NetLogWithSource source0 = net::NetLogWithSource::Make(
  138. net::NetLog::Get(), net::NetLogSourceType::URL_REQUEST);
  139. source0.BeginEvent(net::NetLogEventType::REQUEST_ALIVE);
  140. auto capture_mode_waiter = std::make_unique<NetLogCaptureModeWaiter>(
  141. std::vector<net::NetLogCaptureModeSet>{net::NetLogCaptureModeToBit(
  142. net::NetLogCaptureMode::kIncludeSensitive)});
  143. proxy_source_remote->UpdateCaptureModes(
  144. net::NetLogCaptureModeToBit(net::NetLogCaptureMode::kIncludeSensitive));
  145. // Wait for the mojo message to be delivered and the NetLogProxySource to
  146. // start listening for NetLog events.
  147. capture_mode_waiter->WaitForCaptureModeUpdate();
  148. task_environment.FastForwardBy(base::Seconds(5432));
  149. base::TimeTicks source1_start_ticks = base::TimeTicks::Now();
  150. net::NetLogWithSource source1 = net::NetLogWithSource::Make(
  151. net::NetLog::Get(), net::NetLogSourceType::SOCKET);
  152. task_environment.FastForwardBy(base::Seconds(1));
  153. base::TimeTicks source1_event0_ticks = base::TimeTicks::Now();
  154. source1.BeginEvent(net::NetLogEventType::SOCKET_ALIVE);
  155. task_environment.FastForwardBy(base::Seconds(10));
  156. base::TimeTicks source1_event1_ticks = base::TimeTicks::Now();
  157. // Add the second event from a different thread. Use a lambda instead of
  158. // binding to NetLogWithSource::EndEvent since EndEvent is overloaded and
  159. // templatized which seems to confuse BindOnce. Capturing is safe here as
  160. // the test will WaitForExpectedEntries() before completing.
  161. base::ThreadPool::PostTask(
  162. FROM_HERE, base::BindOnce(base::BindLambdaForTesting([&]() {
  163. source1.EndEvent(net::NetLogEventType::SOCKET_ALIVE);
  164. })));
  165. // Wait for all the expected events to be proxied over the mojo pipe and
  166. // recorded.
  167. sink.WaitForExpectedEntries();
  168. capture_mode_waiter = std::make_unique<NetLogCaptureModeWaiter>(
  169. std::vector<net::NetLogCaptureModeSet>{0});
  170. proxy_source_remote->UpdateCaptureModes(0);
  171. // Wait for the mojo message to be delivered and the NetLogProxySource to
  172. // stop listening for NetLog events.
  173. capture_mode_waiter->WaitForCaptureModeUpdate();
  174. // No capture modes are set, so should not get proxied.
  175. net::NetLog::Get()->AddGlobalEntry(net::NetLogEventType::CANCELLED);
  176. // Run any remaining tasks, just in case there any unexpected events getting
  177. // proxied, this should give them a chance to get recorded so the test would
  178. // fail.
  179. task_environment.RunUntilIdle();
  180. const auto& entries = sink.entries();
  181. ASSERT_EQ(kExpectedEventCount, entries.size());
  182. EXPECT_EQ(static_cast<uint32_t>(net::NetLogEventType::SOCKET_ALIVE),
  183. entries[0].type);
  184. EXPECT_EQ(static_cast<uint32_t>(net::NetLogSourceType::SOCKET),
  185. entries[0].source_type);
  186. EXPECT_EQ(source1.source().id, entries[0].source_id);
  187. EXPECT_EQ(source1_start_ticks, entries[0].source_start_time);
  188. EXPECT_EQ(net::NetLogEventPhase::BEGIN, entries[0].phase);
  189. EXPECT_EQ(source1_event0_ticks, entries[0].time);
  190. EXPECT_TRUE(entries[0].params.is_none());
  191. EXPECT_EQ(static_cast<uint32_t>(net::NetLogEventType::SOCKET_ALIVE),
  192. entries[1].type);
  193. EXPECT_EQ(static_cast<uint32_t>(net::NetLogSourceType::SOCKET),
  194. entries[1].source_type);
  195. EXPECT_EQ(source1.source().id, entries[1].source_id);
  196. EXPECT_EQ(source1_start_ticks, entries[1].source_start_time);
  197. EXPECT_EQ(net::NetLogEventPhase::END, entries[1].phase);
  198. EXPECT_EQ(source1_event1_ticks, entries[1].time);
  199. EXPECT_TRUE(entries[1].params.is_none());
  200. }
  201. TEST(NetLogProxySource, ProxiesParamsOfLeastSensitiveCaptureMode) {
  202. base::test::TaskEnvironment task_environment;
  203. const size_t kExpectedEventCount = 3;
  204. mojo::Remote<network::mojom::NetLogProxySource> proxy_source_remote;
  205. mojo::Remote<network::mojom::NetLogProxySink> proxy_sink_remote;
  206. FakeNetLogProxySink sink(proxy_sink_remote.BindNewPipeAndPassReceiver(),
  207. kExpectedEventCount);
  208. net_log::NetLogProxySource net_log_source(
  209. proxy_source_remote.BindNewPipeAndPassReceiver(),
  210. std::move(proxy_sink_remote));
  211. net::NetLogWithSource source0 = net::NetLogWithSource::Make(
  212. net::NetLog::Get(), net::NetLogSourceType::URL_REQUEST);
  213. auto capture_mode_waiter = std::make_unique<NetLogCaptureModeWaiter>(
  214. std::vector<net::NetLogCaptureModeSet>{net::NetLogCaptureModeToBit(
  215. net::NetLogCaptureMode::kIncludeSensitive)});
  216. proxy_source_remote->UpdateCaptureModes(
  217. net::NetLogCaptureModeToBit(net::NetLogCaptureMode::kIncludeSensitive));
  218. // Wait for the mojo message to be delivered and the NetLogProxySource to
  219. // start listening for NetLog events.
  220. capture_mode_waiter->WaitForCaptureModeUpdate();
  221. source0.BeginEvent(net::NetLogEventType::REQUEST_ALIVE,
  222. &NetLogCaptureModeToParams);
  223. capture_mode_waiter = std::make_unique<NetLogCaptureModeWaiter>(
  224. std::vector<net::NetLogCaptureModeSet>{
  225. 0, net::NetLogCaptureModeToBit(net::NetLogCaptureMode::kDefault)});
  226. proxy_source_remote->UpdateCaptureModes(
  227. net::NetLogCaptureModeToBit(net::NetLogCaptureMode::kDefault) |
  228. net::NetLogCaptureModeToBit(net::NetLogCaptureMode::kIncludeSensitive));
  229. // Wait for the mojo message to be delivered and the NetLogProxySource to
  230. // update the level it is listening for NetLog events.
  231. // Should be listening at the default level only, as that is the lowest
  232. // level in the capture mode set.
  233. capture_mode_waiter->WaitForCaptureModeUpdate();
  234. source0.AddEvent(net::NetLogEventType::FAILED, &NetLogCaptureModeToParams);
  235. proxy_source_remote->UpdateCaptureModes(
  236. net::NetLogCaptureModeToBit(net::NetLogCaptureMode::kDefault));
  237. // NetLogProxySource's observer capture mode shouldn't change, so can't use
  238. // NetLogCaptureModeWaiter here. Just run the task loops.
  239. task_environment.RunUntilIdle();
  240. source0.EndEvent(net::NetLogEventType::REQUEST_ALIVE,
  241. &NetLogCaptureModeToParams);
  242. // Wait for all the expected events to be proxied over the mojo pipe and
  243. // recorded.
  244. sink.WaitForExpectedEntries();
  245. const auto& entries = sink.entries();
  246. ASSERT_EQ(kExpectedEventCount, entries.size());
  247. EXPECT_EQ(static_cast<uint32_t>(net::NetLogEventType::REQUEST_ALIVE),
  248. entries[0].type);
  249. EXPECT_EQ(static_cast<uint32_t>(net::NetLogSourceType::URL_REQUEST),
  250. entries[0].source_type);
  251. EXPECT_EQ(source0.source().id, entries[0].source_id);
  252. EXPECT_EQ(net::NetLogEventPhase::BEGIN, entries[0].phase);
  253. ASSERT_TRUE(entries[0].params.is_dict());
  254. EXPECT_EQ(1U, entries[0].params.DictSize());
  255. const std::string* param = entries[0].params.FindStringKey("capture_mode");
  256. ASSERT_TRUE(param);
  257. EXPECT_EQ("kIncludeSensitive", *param);
  258. EXPECT_EQ(static_cast<uint32_t>(net::NetLogEventType::FAILED),
  259. entries[1].type);
  260. EXPECT_EQ(static_cast<uint32_t>(net::NetLogSourceType::URL_REQUEST),
  261. entries[1].source_type);
  262. EXPECT_EQ(source0.source().id, entries[1].source_id);
  263. EXPECT_EQ(net::NetLogEventPhase::NONE, entries[1].phase);
  264. ASSERT_TRUE(entries[1].params.is_dict());
  265. EXPECT_EQ(1U, entries[1].params.DictSize());
  266. param = entries[1].params.FindStringKey("capture_mode");
  267. ASSERT_TRUE(param);
  268. EXPECT_EQ("kDefault", *param);
  269. EXPECT_EQ(static_cast<uint32_t>(net::NetLogEventType::REQUEST_ALIVE),
  270. entries[2].type);
  271. EXPECT_EQ(static_cast<uint32_t>(net::NetLogSourceType::URL_REQUEST),
  272. entries[2].source_type);
  273. EXPECT_EQ(source0.source().id, entries[2].source_id);
  274. EXPECT_EQ(net::NetLogEventPhase::END, entries[2].phase);
  275. ASSERT_TRUE(entries[2].params.is_dict());
  276. EXPECT_EQ(1U, entries[2].params.DictSize());
  277. param = entries[2].params.FindStringKey("capture_mode");
  278. ASSERT_TRUE(param);
  279. EXPECT_EQ("kDefault", *param);
  280. }