file_net_log_observer.cc 31 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840841842843844845846847848
  1. // Copyright 2016 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 "net/log/file_net_log_observer.h"
  5. #include <algorithm>
  6. #include <memory>
  7. #include <string>
  8. #include <utility>
  9. #include "base/bind.h"
  10. #include "base/containers/queue.h"
  11. #include "base/files/file.h"
  12. #include "base/files/file_util.h"
  13. #include "base/json/json_writer.h"
  14. #include "base/logging.h"
  15. #include "base/memory/ptr_util.h"
  16. #include "base/numerics/clamped_math.h"
  17. #include "base/strings/string_number_conversions.h"
  18. #include "base/synchronization/lock.h"
  19. #include "base/task/sequenced_task_runner.h"
  20. #include "base/task/thread_pool.h"
  21. #include "base/values.h"
  22. #include "net/log/net_log_capture_mode.h"
  23. #include "net/log/net_log_entry.h"
  24. #include "net/log/net_log_util.h"
  25. #include "net/url_request/url_request_context.h"
  26. namespace {
  27. // Number of events that can build up in |write_queue_| before a task is posted
  28. // to the file task runner to flush them to disk.
  29. const int kNumWriteQueueEvents = 15;
  30. // TODO(eroman): Should use something other than 10 for number of files?
  31. const int kDefaultNumFiles = 10;
  32. scoped_refptr<base::SequencedTaskRunner> CreateFileTaskRunner() {
  33. // The tasks posted to this sequenced task runner do synchronous File I/O for
  34. // the purposes of writing NetLog files.
  35. //
  36. // These intentionally block shutdown to ensure the log file has finished
  37. // being written.
  38. return base::ThreadPool::CreateSequencedTaskRunner(
  39. {base::MayBlock(), base::TaskPriority::USER_VISIBLE,
  40. base::TaskShutdownBehavior::BLOCK_SHUTDOWN});
  41. }
  42. // Truncates a file, also reseting the seek position.
  43. void TruncateFile(base::File* file) {
  44. if (!file->IsValid())
  45. return;
  46. file->Seek(base::File::FROM_BEGIN, 0);
  47. file->SetLength(0);
  48. }
  49. // Opens |path| in write mode.
  50. base::File OpenFileForWrite(const base::FilePath& path) {
  51. base::File result(path,
  52. base::File::FLAG_CREATE_ALWAYS | base::File::FLAG_WRITE);
  53. LOG_IF(ERROR, !result.IsValid()) << "Failed opening: " << path.value();
  54. return result;
  55. }
  56. // Helper that writes data to a file. |file->IsValid()| may be false,
  57. // in which case nothing will be written. Returns the number of bytes
  58. // successfully written (may be less than input data in case of errors).
  59. size_t WriteToFile(base::File* file,
  60. base::StringPiece data1,
  61. base::StringPiece data2 = base::StringPiece(),
  62. base::StringPiece data3 = base::StringPiece()) {
  63. size_t bytes_written = 0;
  64. if (file->IsValid()) {
  65. // Append each of data1, data2 and data3.
  66. if (!data1.empty())
  67. bytes_written +=
  68. std::max(0, file->WriteAtCurrentPos(data1.data(), data1.size()));
  69. if (!data2.empty())
  70. bytes_written +=
  71. std::max(0, file->WriteAtCurrentPos(data2.data(), data2.size()));
  72. if (!data3.empty())
  73. bytes_written +=
  74. std::max(0, file->WriteAtCurrentPos(data3.data(), data3.size()));
  75. }
  76. return bytes_written;
  77. }
  78. // Copies all of the data at |source_path| and appends it to |destination_file|,
  79. // then deletes |source_path|.
  80. void AppendToFileThenDelete(const base::FilePath& source_path,
  81. base::File* destination_file,
  82. char* read_buffer,
  83. size_t read_buffer_size) {
  84. base::ScopedFILE source_file(base::OpenFile(source_path, "rb"));
  85. if (!source_file)
  86. return;
  87. // Read |source_path|'s contents in chunks of read_buffer_size and append
  88. // to |destination_file|.
  89. size_t num_bytes_read;
  90. while ((num_bytes_read =
  91. fread(read_buffer, 1, read_buffer_size, source_file.get())) > 0) {
  92. WriteToFile(destination_file,
  93. base::StringPiece(read_buffer, num_bytes_read));
  94. }
  95. // Now that it has been copied, delete the source file.
  96. source_file.reset();
  97. base::DeleteFile(source_path);
  98. }
  99. base::FilePath SiblingInprogressDirectory(const base::FilePath& log_path) {
  100. return log_path.AddExtension(FILE_PATH_LITERAL(".inprogress"));
  101. }
  102. } // namespace
  103. namespace net {
  104. // Used to store events to be written to file.
  105. using EventQueue = base::queue<std::unique_ptr<std::string>>;
  106. // WriteQueue receives events from FileNetLogObserver on the main thread and
  107. // holds them in a queue until they are drained from the queue and written to
  108. // file on the file task runner.
  109. //
  110. // WriteQueue contains the resources shared between the main thread and the
  111. // file task runner. |lock_| must be acquired to read or write to |queue_| and
  112. // |memory_|.
  113. //
  114. // WriteQueue is refcounted and should be destroyed once all events on the
  115. // file task runner have finished executing.
  116. class FileNetLogObserver::WriteQueue
  117. : public base::RefCountedThreadSafe<WriteQueue> {
  118. public:
  119. // |memory_max| indicates the maximum amount of memory that the virtual write
  120. // queue can use. If |memory_| exceeds |memory_max_|, the |queue_| of events
  121. // is overwritten.
  122. explicit WriteQueue(uint64_t memory_max);
  123. WriteQueue(const WriteQueue&) = delete;
  124. WriteQueue& operator=(const WriteQueue&) = delete;
  125. // Adds |event| to |queue_|. Also manages the size of |memory_|; if it
  126. // exceeds |memory_max_|, then old events are dropped from |queue_| without
  127. // being written to file.
  128. //
  129. // Returns the number of events in the |queue_|.
  130. size_t AddEntryToQueue(std::unique_ptr<std::string> event);
  131. // Swaps |queue_| with |local_queue|. |local_queue| should be empty, so that
  132. // |queue_| is emptied. Resets |memory_| to 0.
  133. void SwapQueue(EventQueue* local_queue);
  134. private:
  135. friend class base::RefCountedThreadSafe<WriteQueue>;
  136. ~WriteQueue();
  137. // Queue of events to be written, shared between main thread and file task
  138. // runner. Main thread adds events to the queue and the file task runner
  139. // drains them and writes the events to file.
  140. //
  141. // |lock_| must be acquired to read or write to this.
  142. EventQueue queue_;
  143. // Tracks how much memory is being used by the virtual write queue.
  144. // Incremented in AddEntryToQueue() when events are added to the
  145. // buffer, and decremented when SwapQueue() is called and the file task
  146. // runner's local queue is swapped with the shared write queue.
  147. //
  148. // |lock_| must be acquired to read or write to this.
  149. uint64_t memory_ = 0;
  150. // Indicates the maximum amount of memory that the |queue_| is allowed to
  151. // use.
  152. const uint64_t memory_max_;
  153. // Protects access to |queue_| and |memory_|.
  154. //
  155. // A lock is necessary because |queue_| and |memory_| are shared between the
  156. // file task runner and the main thread. NetLog's lock protects OnAddEntry(),
  157. // which calls AddEntryToQueue(), but it does not protect access to the
  158. // observer's member variables. Thus, a race condition exists if a thread is
  159. // calling OnAddEntry() at the same time that the file task runner is
  160. // accessing |memory_| and |queue_| to write events to file. The |queue_| and
  161. // |memory_| counter are necessary to bound the amount of memory that is used
  162. // for the queue in the event that the file task runner lags significantly
  163. // behind the main thread in writing events to file.
  164. base::Lock lock_;
  165. };
  166. // FileWriter is responsible for draining events from a WriteQueue and writing
  167. // them to disk. FileWriter can be constructed on any thread, and
  168. // afterwards is only accessed on the file task runner.
  169. class FileNetLogObserver::FileWriter {
  170. public:
  171. // If max_event_file_size == kNoLimit, then no limit is enforced.
  172. FileWriter(const base::FilePath& log_path,
  173. const base::FilePath& inprogress_dir_path,
  174. absl::optional<base::File> pre_existing_log_file,
  175. uint64_t max_event_file_size,
  176. size_t total_num_event_files,
  177. scoped_refptr<base::SequencedTaskRunner> task_runner);
  178. FileWriter(const FileWriter&) = delete;
  179. FileWriter& operator=(const FileWriter&) = delete;
  180. ~FileWriter();
  181. // Writes |constants_value| to disk and opens the events array (closed in
  182. // Stop()).
  183. void Initialize(std::unique_ptr<base::Value> constants_value);
  184. // Closes the events array opened in Initialize() and writes |polled_data| to
  185. // disk. If |polled_data| cannot be converted to proper JSON, then it
  186. // is ignored.
  187. void Stop(std::unique_ptr<base::Value> polled_data);
  188. // Drains |queue_| from WriteQueue into a local file queue and writes the
  189. // events in the queue to disk.
  190. void Flush(scoped_refptr<WriteQueue> write_queue);
  191. // Deletes all netlog files. It is not valid to call any method of
  192. // FileNetLogObserver after DeleteAllFiles().
  193. void DeleteAllFiles();
  194. void FlushThenStop(scoped_refptr<WriteQueue> write_queue,
  195. std::unique_ptr<base::Value> polled_data);
  196. private:
  197. // Returns true if there is no file size bound to enforce.
  198. //
  199. // When operating in unbounded mode, the implementation is optimized to stream
  200. // writes to a single file, rather than chunking them across temporary event
  201. // files.
  202. bool IsUnbounded() const;
  203. bool IsBounded() const;
  204. // Increments |current_event_file_number_|, and updates all state relating to
  205. // the current event file (open file handle, num bytes written, current file
  206. // number).
  207. void IncrementCurrentEventFile();
  208. // Returns the path to the event file having |index|. This looks like
  209. // "LOGDIR/event_file_<index>.json".
  210. base::FilePath GetEventFilePath(size_t index) const;
  211. // Gets the file path where constants are saved at the start of
  212. // logging. This looks like "LOGDIR/constants.json".
  213. base::FilePath GetConstantsFilePath() const;
  214. // Gets the file path where the final data is written at the end of logging.
  215. // This looks like "LOGDIR/end_netlog.json".
  216. base::FilePath GetClosingFilePath() const;
  217. // Returns the corresponding index for |file_number|. File "numbers" are a
  218. // monotonically increasing identifier that start at 1 (a value of zero means
  219. // it is uninitialized), whereas the file "index" is a bounded value that
  220. // wraps and identifies the file path to use.
  221. //
  222. // Keeping track of the current number rather than index makes it a bit easier
  223. // to assemble a file at the end, since it is unambiguous which paths have
  224. // been used/re-used.
  225. size_t FileNumberToIndex(size_t file_number) const;
  226. // Writes |constants_value| to a file.
  227. static void WriteConstantsToFile(std::unique_ptr<base::Value> constants_value,
  228. base::File* file);
  229. // Writes |polled_data| to a file.
  230. static void WritePolledDataToFile(std::unique_ptr<base::Value> polled_data,
  231. base::File* file);
  232. // If any events were written (wrote_event_bytes_), rewinds |file| by 2 bytes
  233. // in order to overwrite the trailing ",\n" that was written by the last event
  234. // line.
  235. void RewindIfWroteEventBytes(base::File* file) const;
  236. // Concatenates all the log files to assemble the final
  237. // |final_log_file_|. This single "stitched" file is what other
  238. // log ingesting tools expect.
  239. void StitchFinalLogFile();
  240. // Creates the .inprogress directory used by bounded mode.
  241. void CreateInprogressDirectory();
  242. // The file the final netlog is written to. In bounded mode this is mostly
  243. // written to once logging is stopped, whereas in unbounded mode events will
  244. // be directly written to it.
  245. base::File final_log_file_;
  246. // If non-empty, this is the path to |final_log_file_| created and owned
  247. // by FileWriter itself (rather than passed in to Create*PreExisting
  248. // methods of FileNetLogObserver).
  249. const base::FilePath final_log_path_;
  250. // Path to a (temporary) directory where files are written in bounded mode.
  251. // When logging is stopped these files are stitched together and written
  252. // to the final log path.
  253. const base::FilePath inprogress_dir_path_;
  254. // Holds the numbered events file where data is currently being written to.
  255. // The file path of this file is GetEventFilePath(current_event_file_number_).
  256. // The file may be !IsValid() if an error previously occurred opening the
  257. // file, or logging has been stopped.
  258. base::File current_event_file_;
  259. uint64_t current_event_file_size_;
  260. // Indicates the total number of netlog event files allowed.
  261. // (The files GetConstantsFilePath() and GetClosingFilePath() do
  262. // not count against the total.)
  263. const size_t total_num_event_files_;
  264. // Counter for the events file currently being written into. See
  265. // FileNumberToIndex() for an explanation of what "number" vs "index" mean.
  266. size_t current_event_file_number_ = 0;
  267. // Indicates the maximum size of each individual events file. May be kNoLimit
  268. // to indicate that it can grow arbitrarily large.
  269. const uint64_t max_event_file_size_;
  270. // Whether any bytes were written for events. This is used to properly format
  271. // JSON (events list shouldn't end with a comma).
  272. bool wrote_event_bytes_ = false;
  273. // Task runner for doing file operations.
  274. const scoped_refptr<base::SequencedTaskRunner> task_runner_;
  275. };
  276. std::unique_ptr<FileNetLogObserver> FileNetLogObserver::CreateBounded(
  277. const base::FilePath& log_path,
  278. uint64_t max_total_size,
  279. NetLogCaptureMode capture_mode,
  280. std::unique_ptr<base::Value> constants) {
  281. return CreateInternal(log_path, SiblingInprogressDirectory(log_path),
  282. absl::nullopt, max_total_size, kDefaultNumFiles,
  283. capture_mode, std::move(constants));
  284. }
  285. std::unique_ptr<FileNetLogObserver> FileNetLogObserver::CreateUnbounded(
  286. const base::FilePath& log_path,
  287. NetLogCaptureMode capture_mode,
  288. std::unique_ptr<base::Value> constants) {
  289. return CreateInternal(log_path, base::FilePath(), absl::nullopt, kNoLimit,
  290. kDefaultNumFiles, capture_mode, std::move(constants));
  291. }
  292. std::unique_ptr<FileNetLogObserver>
  293. FileNetLogObserver::CreateBoundedPreExisting(
  294. const base::FilePath& inprogress_dir_path,
  295. base::File output_file,
  296. uint64_t max_total_size,
  297. NetLogCaptureMode capture_mode,
  298. std::unique_ptr<base::Value> constants) {
  299. return CreateInternal(base::FilePath(), inprogress_dir_path,
  300. absl::make_optional<base::File>(std::move(output_file)),
  301. max_total_size, kDefaultNumFiles, capture_mode,
  302. std::move(constants));
  303. }
  304. std::unique_ptr<FileNetLogObserver>
  305. FileNetLogObserver::CreateUnboundedPreExisting(
  306. base::File output_file,
  307. NetLogCaptureMode capture_mode,
  308. std::unique_ptr<base::Value> constants) {
  309. return CreateInternal(base::FilePath(), base::FilePath(),
  310. absl::make_optional<base::File>(std::move(output_file)),
  311. kNoLimit, kDefaultNumFiles, capture_mode,
  312. std::move(constants));
  313. }
  314. FileNetLogObserver::~FileNetLogObserver() {
  315. if (net_log()) {
  316. // StopObserving was not called.
  317. net_log()->RemoveObserver(this);
  318. file_task_runner_->PostTask(
  319. FROM_HERE,
  320. base::BindOnce(&FileNetLogObserver::FileWriter::DeleteAllFiles,
  321. base::Unretained(file_writer_.get())));
  322. }
  323. file_task_runner_->DeleteSoon(FROM_HERE, file_writer_.release());
  324. }
  325. void FileNetLogObserver::StartObserving(NetLog* net_log) {
  326. net_log->AddObserver(this, capture_mode_);
  327. }
  328. void FileNetLogObserver::StopObserving(std::unique_ptr<base::Value> polled_data,
  329. base::OnceClosure optional_callback) {
  330. net_log()->RemoveObserver(this);
  331. base::OnceClosure bound_flush_then_stop =
  332. base::BindOnce(&FileNetLogObserver::FileWriter::FlushThenStop,
  333. base::Unretained(file_writer_.get()), write_queue_,
  334. std::move(polled_data));
  335. // Note that PostTaskAndReply() requires a non-null closure.
  336. if (!optional_callback.is_null()) {
  337. file_task_runner_->PostTaskAndReply(FROM_HERE,
  338. std::move(bound_flush_then_stop),
  339. std::move(optional_callback));
  340. } else {
  341. file_task_runner_->PostTask(FROM_HERE, std::move(bound_flush_then_stop));
  342. }
  343. }
  344. void FileNetLogObserver::OnAddEntry(const NetLogEntry& entry) {
  345. auto json = std::make_unique<std::string>();
  346. *json = SerializeNetLogValueToJson(entry.ToValue());
  347. size_t queue_size = write_queue_->AddEntryToQueue(std::move(json));
  348. // If events build up in |write_queue_|, trigger the file task runner to drain
  349. // the queue. Because only 1 item is added to the queue at a time, if
  350. // queue_size > kNumWriteQueueEvents a task has already been posted, or will
  351. // be posted.
  352. if (queue_size == kNumWriteQueueEvents) {
  353. file_task_runner_->PostTask(
  354. FROM_HERE,
  355. base::BindOnce(&FileNetLogObserver::FileWriter::Flush,
  356. base::Unretained(file_writer_.get()), write_queue_));
  357. }
  358. }
  359. std::unique_ptr<FileNetLogObserver> FileNetLogObserver::CreateBoundedForTests(
  360. const base::FilePath& log_path,
  361. uint64_t max_total_size,
  362. size_t total_num_event_files,
  363. NetLogCaptureMode capture_mode,
  364. std::unique_ptr<base::Value> constants) {
  365. return CreateInternal(log_path, SiblingInprogressDirectory(log_path),
  366. absl::nullopt, max_total_size, total_num_event_files,
  367. capture_mode, std::move(constants));
  368. }
  369. std::unique_ptr<FileNetLogObserver> FileNetLogObserver::CreateInternal(
  370. const base::FilePath& log_path,
  371. const base::FilePath& inprogress_dir_path,
  372. absl::optional<base::File> pre_existing_log_file,
  373. uint64_t max_total_size,
  374. size_t total_num_event_files,
  375. NetLogCaptureMode capture_mode,
  376. std::unique_ptr<base::Value> constants) {
  377. DCHECK_GT(total_num_event_files, 0u);
  378. scoped_refptr<base::SequencedTaskRunner> file_task_runner =
  379. CreateFileTaskRunner();
  380. const uint64_t max_event_file_size =
  381. max_total_size == kNoLimit ? kNoLimit
  382. : max_total_size / total_num_event_files;
  383. // The FileWriter uses a soft limit to write events to file that allows
  384. // the size of the file to exceed the limit, but the WriteQueue uses a hard
  385. // limit which the size of |WriteQueue::queue_| cannot exceed. Thus, the
  386. // FileWriter may write more events to file than can be contained by
  387. // the WriteQueue if they have the same size limit. The maximum size of the
  388. // WriteQueue is doubled to allow |WriteQueue::queue_| to hold enough events
  389. // for the FileWriter to fill all files. As long as all events have
  390. // sizes <= the size of an individual event file, the discrepancy between the
  391. // hard limit and the soft limit will not cause an issue.
  392. // TODO(dconnol): Handle the case when the WriteQueue still doesn't
  393. // contain enough events to fill all files, because of very large events
  394. // relative to file size.
  395. auto file_writer = std::make_unique<FileWriter>(
  396. log_path, inprogress_dir_path, std::move(pre_existing_log_file),
  397. max_event_file_size, total_num_event_files, file_task_runner);
  398. uint64_t write_queue_memory_max =
  399. base::MakeClampedNum<uint64_t>(max_total_size) * 2;
  400. return base::WrapUnique(new FileNetLogObserver(
  401. file_task_runner, std::move(file_writer),
  402. base::MakeRefCounted<WriteQueue>(write_queue_memory_max), capture_mode,
  403. std::move(constants)));
  404. }
  405. FileNetLogObserver::FileNetLogObserver(
  406. scoped_refptr<base::SequencedTaskRunner> file_task_runner,
  407. std::unique_ptr<FileWriter> file_writer,
  408. scoped_refptr<WriteQueue> write_queue,
  409. NetLogCaptureMode capture_mode,
  410. std::unique_ptr<base::Value> constants)
  411. : file_task_runner_(std::move(file_task_runner)),
  412. write_queue_(std::move(write_queue)),
  413. file_writer_(std::move(file_writer)),
  414. capture_mode_(capture_mode) {
  415. if (!constants)
  416. constants = std::make_unique<base::Value>(GetNetConstants());
  417. DCHECK(constants->is_dict());
  418. DCHECK(!constants->GetDict().Find("logCaptureMode"));
  419. constants->GetDict().Set("logCaptureMode", CaptureModeToString(capture_mode));
  420. file_task_runner_->PostTask(
  421. FROM_HERE, base::BindOnce(&FileNetLogObserver::FileWriter::Initialize,
  422. base::Unretained(file_writer_.get()),
  423. std::move(constants)));
  424. }
  425. std::string FileNetLogObserver::CaptureModeToString(NetLogCaptureMode mode) {
  426. switch (mode) {
  427. case NetLogCaptureMode::kDefault:
  428. return "Default";
  429. case NetLogCaptureMode::kIncludeSensitive:
  430. return "IncludeSensitive";
  431. case NetLogCaptureMode::kEverything:
  432. return "Everything";
  433. }
  434. NOTREACHED();
  435. return "UNKNOWN";
  436. }
  437. FileNetLogObserver::WriteQueue::WriteQueue(uint64_t memory_max)
  438. : memory_max_(memory_max) {}
  439. size_t FileNetLogObserver::WriteQueue::AddEntryToQueue(
  440. std::unique_ptr<std::string> event) {
  441. base::AutoLock lock(lock_);
  442. memory_ += event->size();
  443. queue_.push(std::move(event));
  444. while (memory_ > memory_max_ && !queue_.empty()) {
  445. // Delete oldest events in the queue.
  446. DCHECK(queue_.front());
  447. memory_ -= queue_.front()->size();
  448. queue_.pop();
  449. }
  450. return queue_.size();
  451. }
  452. void FileNetLogObserver::WriteQueue::SwapQueue(EventQueue* local_queue) {
  453. DCHECK(local_queue->empty());
  454. base::AutoLock lock(lock_);
  455. queue_.swap(*local_queue);
  456. memory_ = 0;
  457. }
  458. FileNetLogObserver::WriteQueue::~WriteQueue() = default;
  459. FileNetLogObserver::FileWriter::FileWriter(
  460. const base::FilePath& log_path,
  461. const base::FilePath& inprogress_dir_path,
  462. absl::optional<base::File> pre_existing_log_file,
  463. uint64_t max_event_file_size,
  464. size_t total_num_event_files,
  465. scoped_refptr<base::SequencedTaskRunner> task_runner)
  466. : final_log_path_(log_path),
  467. inprogress_dir_path_(inprogress_dir_path),
  468. total_num_event_files_(total_num_event_files),
  469. max_event_file_size_(max_event_file_size),
  470. task_runner_(std::move(task_runner)) {
  471. DCHECK_EQ(pre_existing_log_file.has_value(), log_path.empty());
  472. DCHECK_EQ(IsBounded(), !inprogress_dir_path.empty());
  473. if (pre_existing_log_file.has_value()) {
  474. // pre_existing_log_file.IsValid() being false is fine.
  475. final_log_file_ = std::move(pre_existing_log_file.value());
  476. }
  477. }
  478. FileNetLogObserver::FileWriter::~FileWriter() = default;
  479. void FileNetLogObserver::FileWriter::Initialize(
  480. std::unique_ptr<base::Value> constants_value) {
  481. DCHECK(task_runner_->RunsTasksInCurrentSequence());
  482. // Open the final log file, and keep it open for the duration of logging (even
  483. // in bounded mode).
  484. if (!final_log_path_.empty())
  485. final_log_file_ = OpenFileForWrite(final_log_path_);
  486. else
  487. TruncateFile(&final_log_file_);
  488. if (IsBounded()) {
  489. CreateInprogressDirectory();
  490. base::File constants_file = OpenFileForWrite(GetConstantsFilePath());
  491. WriteConstantsToFile(std::move(constants_value), &constants_file);
  492. } else {
  493. WriteConstantsToFile(std::move(constants_value), &final_log_file_);
  494. }
  495. }
  496. void FileNetLogObserver::FileWriter::Stop(
  497. std::unique_ptr<base::Value> polled_data) {
  498. DCHECK(task_runner_->RunsTasksInCurrentSequence());
  499. // Write out the polled data.
  500. if (IsBounded()) {
  501. base::File closing_file = OpenFileForWrite(GetClosingFilePath());
  502. WritePolledDataToFile(std::move(polled_data), &closing_file);
  503. } else {
  504. RewindIfWroteEventBytes(&final_log_file_);
  505. WritePolledDataToFile(std::move(polled_data), &final_log_file_);
  506. }
  507. // If operating in bounded mode, the events were written to separate files
  508. // within |inprogress_dir_path_|. Assemble them into the final destination
  509. // file.
  510. if (IsBounded())
  511. StitchFinalLogFile();
  512. // Ensure the final log file has been flushed.
  513. final_log_file_.Close();
  514. }
  515. void FileNetLogObserver::FileWriter::Flush(
  516. scoped_refptr<FileNetLogObserver::WriteQueue> write_queue) {
  517. DCHECK(task_runner_->RunsTasksInCurrentSequence());
  518. EventQueue local_file_queue;
  519. write_queue->SwapQueue(&local_file_queue);
  520. while (!local_file_queue.empty()) {
  521. base::File* output_file;
  522. // If in bounded mode, output events to the current event file. Otherwise
  523. // output events to the final log path.
  524. if (IsBounded()) {
  525. if (current_event_file_number_ == 0 ||
  526. current_event_file_size_ >= max_event_file_size_) {
  527. IncrementCurrentEventFile();
  528. }
  529. output_file = &current_event_file_;
  530. } else {
  531. output_file = &final_log_file_;
  532. }
  533. size_t bytes_written =
  534. WriteToFile(output_file, *local_file_queue.front(), ",\n");
  535. wrote_event_bytes_ |= bytes_written > 0;
  536. // Keep track of the filesize for current event file when in bounded mode.
  537. if (IsBounded())
  538. current_event_file_size_ += bytes_written;
  539. local_file_queue.pop();
  540. }
  541. }
  542. void FileNetLogObserver::FileWriter::DeleteAllFiles() {
  543. DCHECK(task_runner_->RunsTasksInCurrentSequence());
  544. final_log_file_.Close();
  545. if (IsBounded()) {
  546. current_event_file_.Close();
  547. base::DeletePathRecursively(inprogress_dir_path_);
  548. }
  549. // Only delete |final_log_file_| if it was created internally.
  550. // (If it was provided as a base::File by the caller, don't try to delete it).
  551. if (!final_log_path_.empty())
  552. base::DeleteFile(final_log_path_);
  553. }
  554. void FileNetLogObserver::FileWriter::FlushThenStop(
  555. scoped_refptr<FileNetLogObserver::WriteQueue> write_queue,
  556. std::unique_ptr<base::Value> polled_data) {
  557. Flush(write_queue);
  558. Stop(std::move(polled_data));
  559. }
  560. bool FileNetLogObserver::FileWriter::IsUnbounded() const {
  561. return max_event_file_size_ == kNoLimit;
  562. }
  563. bool FileNetLogObserver::FileWriter::IsBounded() const {
  564. return !IsUnbounded();
  565. }
  566. void FileNetLogObserver::FileWriter::IncrementCurrentEventFile() {
  567. DCHECK(task_runner_->RunsTasksInCurrentSequence());
  568. DCHECK(IsBounded());
  569. current_event_file_number_++;
  570. current_event_file_ = OpenFileForWrite(
  571. GetEventFilePath(FileNumberToIndex(current_event_file_number_)));
  572. current_event_file_size_ = 0;
  573. }
  574. base::FilePath FileNetLogObserver::FileWriter::GetEventFilePath(
  575. size_t index) const {
  576. DCHECK_LT(index, total_num_event_files_);
  577. DCHECK(IsBounded());
  578. return inprogress_dir_path_.AppendASCII(
  579. "event_file_" + base::NumberToString(index) + ".json");
  580. }
  581. base::FilePath FileNetLogObserver::FileWriter::GetConstantsFilePath() const {
  582. return inprogress_dir_path_.AppendASCII("constants.json");
  583. }
  584. base::FilePath FileNetLogObserver::FileWriter::GetClosingFilePath() const {
  585. return inprogress_dir_path_.AppendASCII("end_netlog.json");
  586. }
  587. size_t FileNetLogObserver::FileWriter::FileNumberToIndex(
  588. size_t file_number) const {
  589. DCHECK_GT(file_number, 0u);
  590. // Note that "file numbers" start at 1 not 0.
  591. return (file_number - 1) % total_num_event_files_;
  592. }
  593. void FileNetLogObserver::FileWriter::WriteConstantsToFile(
  594. std::unique_ptr<base::Value> constants_value,
  595. base::File* file) {
  596. // Print constants to file and open events array.
  597. std::string json = SerializeNetLogValueToJson(*constants_value);
  598. WriteToFile(file, "{\"constants\":", json, ",\n\"events\": [\n");
  599. }
  600. void FileNetLogObserver::FileWriter::WritePolledDataToFile(
  601. std::unique_ptr<base::Value> polled_data,
  602. base::File* file) {
  603. // Close the events array.
  604. WriteToFile(file, "]");
  605. // Write the polled data (if any).
  606. if (polled_data) {
  607. std::string polled_data_json;
  608. base::JSONWriter::Write(*polled_data, &polled_data_json);
  609. if (!polled_data_json.empty())
  610. WriteToFile(file, ",\n\"polledData\": ", polled_data_json, "\n");
  611. }
  612. // Close the log.
  613. WriteToFile(file, "}\n");
  614. }
  615. void FileNetLogObserver::FileWriter::RewindIfWroteEventBytes(
  616. base::File* file) const {
  617. if (file->IsValid() && wrote_event_bytes_) {
  618. // To be valid JSON the events array should not end with a comma. If events
  619. // were written though, they will have been terminated with "\n," so strip
  620. // it before closing the events array.
  621. file->Seek(base::File::FROM_END, -2);
  622. }
  623. }
  624. void FileNetLogObserver::FileWriter::StitchFinalLogFile() {
  625. // Make sure all the events files are flushed (as will read them next).
  626. current_event_file_.Close();
  627. // Allocate a 64K buffer used for reading the files. At most kReadBufferSize
  628. // bytes will be in memory at a time.
  629. const size_t kReadBufferSize = 1 << 16; // 64KiB
  630. auto read_buffer = std::make_unique<char[]>(kReadBufferSize);
  631. if (final_log_file_.IsValid()) {
  632. // Truncate the final log file.
  633. TruncateFile(&final_log_file_);
  634. // Append the constants file.
  635. AppendToFileThenDelete(GetConstantsFilePath(), &final_log_file_,
  636. read_buffer.get(), kReadBufferSize);
  637. // Iterate over the events files, from oldest to most recent, and append
  638. // them to the final destination. Note that "file numbers" start at 1 not 0.
  639. size_t end_filenumber = current_event_file_number_ + 1;
  640. size_t begin_filenumber =
  641. current_event_file_number_ <= total_num_event_files_
  642. ? 1
  643. : end_filenumber - total_num_event_files_;
  644. for (size_t filenumber = begin_filenumber; filenumber < end_filenumber;
  645. ++filenumber) {
  646. AppendToFileThenDelete(GetEventFilePath(FileNumberToIndex(filenumber)),
  647. &final_log_file_, read_buffer.get(),
  648. kReadBufferSize);
  649. }
  650. // Account for the final event line ending in a ",\n". Strip it to form
  651. // valid JSON.
  652. RewindIfWroteEventBytes(&final_log_file_);
  653. // Append the polled data.
  654. AppendToFileThenDelete(GetClosingFilePath(), &final_log_file_,
  655. read_buffer.get(), kReadBufferSize);
  656. }
  657. // Delete the inprogress directory (and anything that may still be left inside
  658. // it).
  659. base::DeletePathRecursively(inprogress_dir_path_);
  660. }
  661. void FileNetLogObserver::FileWriter::CreateInprogressDirectory() {
  662. DCHECK(IsBounded());
  663. // If an output file couldn't be created, either creation of intermediate
  664. // files will also fail (if they're in a sibling directory), or are they are
  665. // hidden somewhere the user would be unlikely to find them, so there is
  666. // little reason to progress.
  667. if (!final_log_file_.IsValid())
  668. return;
  669. if (!base::CreateDirectory(inprogress_dir_path_)) {
  670. LOG(WARNING) << "Failed creating directory: "
  671. << inprogress_dir_path_.value();
  672. return;
  673. }
  674. // It is OK if the path is wrong due to encoding - this is really just a
  675. // convenience display for the user in understanding what the file means.
  676. std::string in_progress_path = inprogress_dir_path_.AsUTF8Unsafe();
  677. // Since |final_log_file_| will not be written to until the very end, leave
  678. // some data in it explaining that the real data is currently in the
  679. // .inprogress directory. This ordinarily won't be visible (overwritten when
  680. // stopping) however if logging does not end gracefully the comments are
  681. // useful for recovery.
  682. WriteToFile(
  683. &final_log_file_, "Logging is in progress writing data to:\n ",
  684. in_progress_path,
  685. "\n\n"
  686. "That data will be stitched into a single file (this one) once logging\n"
  687. "has stopped.\n"
  688. "\n"
  689. "If logging was interrupted, you can stitch a NetLog file out of the\n"
  690. ".inprogress directory manually using:\n"
  691. "\n"
  692. "https://chromium.googlesource.com/chromium/src/+/main/net/tools/"
  693. "stitch_net_log_files.py\n");
  694. }
  695. std::string SerializeNetLogValueToJson(const base::Value& value) {
  696. // Omit trailing ".0" when printing a DOUBLE that is representable as a 64-bit
  697. // integer. This makes the values returned by NetLogNumberValue() look more
  698. // pleasant (for representing integers between 32 and 53 bits large).
  699. int options = base::JSONWriter::OPTIONS_OMIT_DOUBLE_TYPE_PRESERVATION;
  700. std::string json;
  701. bool ok = base::JSONWriter::WriteWithOptions(value, options, &json);
  702. // Serialization shouldn't fail. However it can if a consumer has passed a
  703. // parameter of type BINARY, since JSON serialization can't handle that.
  704. DCHECK(ok);
  705. return json;
  706. }
  707. } // namespace net