net/docs/net-log.md

   1 # NetLog
   2
   3 This document describes the design and use of logging through NetLog.
   4
   5 [TOC]
   6
   7 ## Adding new NetLogging code
   8
   9 Adding information to the NetLog helps debugging. However, logging also requires
  10 careful review as it can impact performance, privacy, and security.
  11
  12 Please add a [net/log/OWNERS](../log/OWNERS) reviewer when adding new NetLog
  13 parameters, or adding information to existing ones.
  14
  15 The high level objectives when adding net logging code are:
  16
  17 * No performance cost when capturing is off.
  18 * Logs captured using [`kDefault`](../log/net_log_capture_mode.h) are safe to
  19   upload and share publicly.
  20 * Capturing using [`kDefault`](../log/net_log_capture_mode.h) has a low
  21   performance impact.
  22 * Logs captured using [`kDefault`](../log/net_log_capture_mode.h) are small
  23   enough to upload to bug reports.
  24 * Events that may emit sensitive information have accompanying unit-tests.
  25 * The event and its possible parameters are documented in
  26   [net_log_event_type_list.h](../log/net_log_event_type_list.h)
  27
  28 To avoid doing work when logging is off, logging code should generally be
  29 conditional on `NetLog::IsCapturing()`. Note that when specifying parameters
  30 via a lambda, the lambda is already conditional on `IsCapturing()`.
  31
  32 ### Binary data and strings
  33
  34 NetLog parameters are specified as a JSON serializable `base::Value`. This has
  35 some subtle implications:
  36
  37 * Do not use `base::Value::Type::STRING` with non-UTF-8 data.
  38 * Do not use `base::Value::Type::BINARY` (the JSON serializer can't handle it)
  39
  40 Instead:
  41
  42 * If the string is likely ASCII or UTF-8, use `NetLogStringValue()`.
  43 * If the string is arbitrary data, use `NetLogBinaryValue()`.
  44 * If the string is guaranteed to be valid UTF-8, you can use
  45   `base::Value::Type::STRING`
  46
  47 Also consider the maximum size of any string parameters:
  48
  49 * If the string could be large, truncate or omit it when using the default
  50   capture mode. Large strings should be relegated to the `kEverything`
  51   capture mode.
  52
  53 ### 64-bit integers
  54
  55 NetLog parameters are specified as a JSON serializable `base::Value` which does
  56 not support 64-bit integers.
  57
  58 Be careful when using `base::Value::SetIntKey()` as it will truncate 64-bit
  59 values to 32-bits.
  60
  61 Instead use `NetLogNumberValue()`.
  62
  63 ### Backwards compatibility
  64
  65 There is no backwards compatibility requirement for NetLog events and their
  66 parameters, so you are free to change their structure/value as needed.
  67
  68 That said, changing core events may have consequences for external consumers of
  69 NetLogs, which rely on the structure and parameters to events for pretty
  70 printing and log analysis.
  71
  72 The [NetLog viewer](https://netlog-viewer.appspot.com/) for instance pretty
  73 prints certain parameters based on their names, and the event name that added
  74 them.
  75
  76 ### Example 1
  77
  78 Add an `PROXY_RESOLUTION_SERVICE` event without any parameters, at all capture
  79 modes.
  80
  81 ```
  82 net_log.BeginEvent(NetLogEventType::PROXY_RESOLUTION_SERVICE);
  83 ```
  84
  85 Analysis:
  86
  87 * Privacy: Logging the event at all capture modes only reveals timing
  88   information.
  89 * Performance: When not logging, has the overhead of an unconditional function
  90   call (`BeginEvent`), and then a branch (test on `IsCapturing()`).
  91 * Size: Minimal data added to NetLog - just one parameterless event per URL
  92   request.
  93
  94 ### Example 2
  95
  96 Add a `FTP_COMMAND_SENT` event, at all capture modes, along with parameters
  97 that describe the FTP command.
  98
  99 ```
 100 if (net_log.IsCapturing()) {
 101   std::string command = BuildCommandForLog();
 102   net_log.AddEventWithStringParams(NetLogEventType::FTP_COMMAND_SENT,
 103                                    "command", command);
 104 }
 105 ```
 106
 107 Analysis:
 108
 109 * Privacy: Low risk given FTP traffic is unencrypted. `BuildCommandForString()`
 110   should additionally best-effort strip any identity information, as this is
 111   being logged at all capture modes.
 112 * Performance: Costs one branch when not capturing. The call to
 113   `BuildCommandForString()` is only executed when capturing.
 114 * Size: Cost is proportional to the average FTP command length and frequency of
 115   FTP, both of which are low. `BuildCommandForLog()` needn't strictly bound the
 116   string length. If a huge FTP command makes it to a NetLog, there is a good
 117   chance that is the problem being debugged.
 118
 119 ### Example 3
 120
 121 Add a `SSL_CERTIFICATES_RECEIVED` event, along with the full certificate chain,
 122 at all capture modes.
 123
 124 ```
 125 net_log.AddEvent(NetLogEventType::SSL_CERTIFICATES_RECEIVED, [&] {
 126   base::Value dict(base::Value::Type::DICTIONARY);
 127   base::Value certs(base::Value::Type::LIST);
 128   std::vector<std::string> encoded_chain;
 129   server_cert_->GetPEMEncodedChain(&encoded_chain);
 130   for (auto& pem : encoded_chain)
 131     certs.Append(std::move(pem));
 132   dict.SetKey("certificates", std::move(certs));
 133   return dict;
 134 });
 135 ```
 136
 137 Analysis:
 138
 139 * Privacy: Low risk as server certificates are generally public data.
 140 * Performance: Costs one branch when logging is off (hidden by template
 141   expansion). The code in the lambda which builds the `base::Value` parameters is only
 142   executed when capturing.
 143 * Size: On average 8K worth of data per request (average of 2K/certificate,
 144   chain length of 3, and the overhead of PEM-encoding). This is heavy-weight
 145   for inclusion at `kDefault` capture mode, however justified based on how
 146   useful the data is.
 147
 148 ### Example 4
 149
 150 Add a `COOKIE_STORE_COOKIE_ADDED` event at all capture modes. Moreover, if the
 151 capture mode is `kIncludeSensitive` or `kEverything`, also logs the cookie's
 152 name and value.
 153
 154 ```
 155 net_log.AddEvent(NetLogEventType::COOKIE_STORE_COOKIE_ADDED,
 156                  [&](NetLogCaptureMode capture_mode) {
 157                    if (!NetLogCaptureIncludesSensitive(capture_mode))
 158                      return base::Value();
 159                    base::Value dict(base::Value::Type::DICTIONARY);
 160                    dict.SetStringKey("name", cookie->Name());
 161                    dict.SetStringKey("value", cookie->Value());
 162                    return dict;
 163                  });
 164 ```
 165
 166 Analysis:
 167
 168 * Privacy: The cookie name and value are not included at the `kDefault` capture
 169   mode, so only cookie counts and timing information is revealed.
 170 * Performance: Costs one branch when logging is off (hidden by template
 171   expansion). The code in the lambda which builds the `base::Value` parameters is only
 172   executed when capturing.
 173 * Size: For default captured logs, has a file size cost proportional to the
 174   number of cookies added. This is borderline justifiable. It would be better
 175   in this case to simply omit the event all together at `kDefault` than to log
 176   a parameterless event, as the parameterless event is not broadly useful.