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