Improve shill logging |
|||
Issue descriptiona) If `ff_debug --level -1` (or a higher verbosity level) is used, libchrome[0] fills up net.log with spammy messages that look like this every time a wifi scan completes: 2018-02-27T20:24:29.188038-08:00 DEBUG shill[28527]: [VERBOSE1:object_proxy.cc(500)] Signal received: message_type: MESSAGE_SIGNAL#012path: /fi/w1/wpa_supplicant1#012interface: fi.w1.wpa_supplicant1#012member: InterfaceRemoved#012sender: :1.1#012signature: o#012serial: 2530#012#012object_path "/fi/w1/wpa_supplicant1/Interfaces/13"#012 These lines can be 8000+ characters long. We should disable them by default. b) If `ff_debug +vpn` is enabled, it would be nice to tell the external VPN daemons to also increase their logging verbosity. This can help in troubleshooting issues in verified mode. [0] https://cs.chromium.org/chromium/src/dbus/object_proxy.cc?rcl=ff50dee02a4198907e13b66db33755404340d726&l=536
,
Mar 24 2018
The following revision refers to this bug: https://chromium.googlesource.com/aosp/platform/system/connectivity/shill/+/4f0d8e29bbc1acecfc00416ac65b1fb5f1d23a6b commit 4f0d8e29bbc1acecfc00416ac65b1fb5f1d23a6b Author: Kevin Cernekee <cernekee@chromium.org> Date: Sat Mar 24 00:29:27 2018 shill: Enable detailed VPN logging through ff_debug Currently, `ff_debug +vpn` with any verbosity level enables: - `--verb 3` in the openvpn options - `debug` in pppd.conf - `charondebug="dmn 2, mgr 2, ike 2, net 2"` in strongswan.conf If verbosity is increased to level -2, the shill/vpn/ code logs some additional diagnostic information: primarily configuration key/value parameters and function invocations. Sometimes it is necessary to log more information: - To debug IPsec IKE negotiation and make sense of packet traces, the session keys must be logged and imported into wireshark. - To debug packet loss or key mismatches in OpenVPN, records of each (tunneled) data packet is often helpful. - To debug keepalives in OpenVPN, records of OpenVPN control messages may be necessary. So, as a general guideline: - `ff_debug --level -2` and below will work the same way it does today - `ff_debug --level -3` will log more detail about control messages - `ff_debug --level -4` will enable per-data-packet logging - `ff_debug --level -5` will log keys and other sensitive data - `ff_debug --level -6` will turn debugging up to the max BUG= chromium:817210 TEST=manually set different loglevels and verify in net.log CQ-DEPEND=CL:958289 Change-Id: I920fed0f3390203d053c5f1cf04b44d7245d8ab3 Reviewed-on: https://chromium-review.googlesource.com/944894 Commit-Ready: Kevin Cernekee <cernekee@chromium.org> Tested-by: Kevin Cernekee <cernekee@chromium.org> Reviewed-by: Ben Chan <benchan@chromium.org> [modify] https://crrev.com/4f0d8e29bbc1acecfc00416ac65b1fb5f1d23a6b/vpn/l2tp_ipsec_driver.cc [modify] https://crrev.com/4f0d8e29bbc1acecfc00416ac65b1fb5f1d23a6b/scope_logger.h [modify] https://crrev.com/4f0d8e29bbc1acecfc00416ac65b1fb5f1d23a6b/vpn/openvpn_driver.cc
,
Mar 24 2018
The following revision refers to this bug: https://chromium.googlesource.com/aosp/platform/system/connectivity/shill/+/4721676f8b8e627545586cd8fe3527f8bc48c51a commit 4721676f8b8e627545586cd8fe3527f8bc48c51a Author: Kevin Cernekee <cernekee@chromium.org> Date: Sat Mar 24 00:29:29 2018 shill: Convert netlink code to use scoped logging Currently this code uses VLOG(), so trying to debug a completely different module will still fill up net.log with RTNL debug prints: ff_debug +vpn ff_debug --level -5 Change the net/ code to use SLOG() instead of VLOG(), with scope "rtnl". This change will only take effect for the in-shill copy of the code; libshill-net will continue to use VLOG() because library users do not implement shill's scoped logging scheme. BUG= chromium:817210 TEST=manually try different loglevels Change-Id: Iad5c0316a871a90a13705a8cfd42add9b61ab669 Reviewed-on: https://chromium-review.googlesource.com/947045 Commit-Ready: Kevin Cernekee <cernekee@chromium.org> Tested-by: Kevin Cernekee <cernekee@chromium.org> Reviewed-by: Matthew Wang <matthewmwang@chromium.org> Reviewed-by: Ben Chan <benchan@chromium.org> [modify] https://crrev.com/4721676f8b8e627545586cd8fe3527f8bc48c51a/net/attribute_list.cc [modify] https://crrev.com/4721676f8b8e627545586cd8fe3527f8bc48c51a/net/netlink_message.cc [modify] https://crrev.com/4721676f8b8e627545586cd8fe3527f8bc48c51a/net/netlink_attribute.cc [modify] https://crrev.com/4721676f8b8e627545586cd8fe3527f8bc48c51a/net/netlink_socket.cc [modify] https://crrev.com/4721676f8b8e627545586cd8fe3527f8bc48c51a/net/rtnl_handler.cc [modify] https://crrev.com/4721676f8b8e627545586cd8fe3527f8bc48c51a/shill.gyp [modify] https://crrev.com/4721676f8b8e627545586cd8fe3527f8bc48c51a/logging.h [modify] https://crrev.com/4721676f8b8e627545586cd8fe3527f8bc48c51a/net/generic_netlink_message.cc [modify] https://crrev.com/4721676f8b8e627545586cd8fe3527f8bc48c51a/net/netlink_manager.cc
,
Mar 24 2018
The following revision refers to this bug: https://chromium.googlesource.com/aosp/platform/system/connectivity/shill/+/6f7a8132cefbebe7456c1e5b7e04ee0fa06ef023 commit 6f7a8132cefbebe7456c1e5b7e04ee0fa06ef023 Author: Kevin Cernekee <cernekee@chromium.org> Date: Sat Mar 24 00:29:27 2018 shill: Compile libshill-net conditionally Build the net/ directory twice. The shared (reusable) version will be built with different compilation flags than the version built into shill. BUG= chromium:817210 TEST=unit tests Change-Id: I332d5f913339a043afd055f7c5c2178bab826ea0 Reviewed-on: https://chromium-review.googlesource.com/947318 Commit-Ready: Kevin Cernekee <cernekee@chromium.org> Tested-by: Kevin Cernekee <cernekee@chromium.org> Reviewed-by: Matthew Wang <matthewmwang@chromium.org> Reviewed-by: Ben Chan <benchan@chromium.org> [modify] https://crrev.com/6f7a8132cefbebe7456c1e5b7e04ee0fa06ef023/shill.gyp
,
Mar 24 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromiumos/platform2/+/aef32231f97fd24ba92c8d1bad3898ab895cdaa1 commit aef32231f97fd24ba92c8d1bad3898ab895cdaa1 Author: Kevin Cernekee <cernekee@chromium.org> Date: Sat Mar 24 00:29:28 2018 vpn: Use numeric --log_level to enable debugging Currently vpn_manager takes two bools: --debug and --ppp_debug. This is insufficiently granular for debugging some types of VPN problems; it is desirable to enable more verbose charon output with e.g. `ff_debug +vpn ; ff_debug --level -5`. BUG= chromium:817210 TEST=manually try different loglevels CQ-DEPEND=CL:944894 Change-Id: I0a7d292346d5b58c05eee680203b80f3c069a110 Reviewed-on: https://chromium-review.googlesource.com/958289 Commit-Ready: Kevin Cernekee <cernekee@chromium.org> Tested-by: Kevin Cernekee <cernekee@chromium.org> Reviewed-by: Matthew Wang <matthewmwang@chromium.org> Reviewed-by: Ben Chan <benchan@chromium.org> [modify] https://crrev.com/aef32231f97fd24ba92c8d1bad3898ab895cdaa1/vpn-manager/service_manager.h [modify] https://crrev.com/aef32231f97fd24ba92c8d1bad3898ab895cdaa1/vpn-manager/l2tp_manager_test.cc [modify] https://crrev.com/aef32231f97fd24ba92c8d1bad3898ab895cdaa1/vpn-manager/l2tp_manager.h [modify] https://crrev.com/aef32231f97fd24ba92c8d1bad3898ab895cdaa1/vpn-manager/ipsec_manager_test.cc [modify] https://crrev.com/aef32231f97fd24ba92c8d1bad3898ab895cdaa1/vpn-manager/service_manager.cc [modify] https://crrev.com/aef32231f97fd24ba92c8d1bad3898ab895cdaa1/vpn-manager/l2tp_manager.cc [modify] https://crrev.com/aef32231f97fd24ba92c8d1bad3898ab895cdaa1/vpn-manager/ipsec_manager.cc [modify] https://crrev.com/aef32231f97fd24ba92c8d1bad3898ab895cdaa1/vpn-manager/l2tpipsec_vpn.cc
,
Aug 3
This bug has an owner, thus, it's been triaged. Changing status to "assigned".
,
Dec 14
Bug doesn't have an active owner, and the description at the top is not relevant for future logging improvements. Closing this up. |
|||
►
Sign in to add a comment |
|||
Comment 1 by bugdroid1@chromium.org
, Mar 16 2018