Google Git
Sign in
cos / third_party / platform2 / refs/heads/main / . / debugd / src / log_tool.cc
blob: 98c4d8bf52a52cf1288ee20e6d0f7189eb7edd46 [file] [log] [blame] [edit]
// Copyright 2012 The ChromiumOS Authors
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
#include "debugd/src/log_tool.h"
#include <glob.h>
#include <grp.h>
#include <inttypes.h>
#include <lzma.h>
#include <pwd.h>
#include <stdint.h>
#include <sys/types.h>
#include <sys/wait.h>
#include <unistd.h>
#include <algorithm>
#include <array>
#include <memory>
#include <optional>
#include <string>
#include <utility>
#include <vector>
#include <base/base64.h>
#include <base/check.h>
#include <base/check_op.h>
#include <base/containers/contains.h>
#include <base/files/file.h>
#include <base/files/file_path.h>
#include <base/files/file_util.h>
#include <base/functional/bind.h>
#include <base/json/json_writer.h>
#include <base/logging.h>
#include <base/strings/string_split.h>
#include <base/strings/string_util.h>
#include <base/strings/stringprintf.h>
#include <base/strings/utf_string_conversion_utils.h>
#include <base/time/time.h>
#include <base/values.h>
#include <brillo/cryptohome.h>
#include <brillo/files/file_util.h>
#include <brillo/files/safe_fd.h>
#include <brillo/key_value_store.h>
#include <brillo/osrelease_reader.h>
#include <brillo/process/process.h>
#include <chromeos/dbus/service_constants.h>
#include <shill/dbus-proxies.h>
#include "debugd/src/bluetooth_utils.h"
#include "debugd/src/constants.h"
#include "debugd/src/error_utils.h"
#include "debugd/src/metrics.h"
#include "debugd/src/perfetto_tool.h"
#include "debugd/src/process_with_output.h"
#include "debugd/src/sandboxed_process.h"
namespace debugd {
using std::string;
using FuncMap = std::map<string, base::OnceCallback<void()>>;
namespace {
constexpr char kRoot[] = "root";
constexpr char kShell[] = "/bin/sh";
constexpr char kLpAdmin[] = "lpadmin";
constexpr char kLpGroup[] = "lp";
constexpr char kLsbReleasePath[] = "/etc/lsb-release";
constexpr char kArcBugReportBackupFileName[] = "arc-bugreport.log";
constexpr char kArcBugReportBackupKey[] = "arc-bugreport-backup";
constexpr char kDaemonStoreBaseDir[] = "/run/daemon-store/debugd/";
constexpr char kLogNotAvailable[] = "<not available>";
constexpr char kLogEmpty[] = "<empty>";
// Maximum time to wait before starting to collect logs from temp files
// generated by log commands. Currently, the client side timeout is 2 minutes.
// We leave 20 seconds for the following remaining tasks:
// - Read logs from temp files.
// - Serialize the logs to JSON.
// - Send the result back to client.
const base::TimeDelta kFeedbackLogTimeout = base::Seconds(100);
// Minimum time in seconds needed to allow shill to test active connections.
const int kConnectionTesterTimeoutSeconds = 3;
// Default running perf for 2 seconds.
constexpr const int kPerfDurationSecs = 2;
// TODO(chinglinyu) Remove after crbug/934702 is fixed.
// The following description is added to 'perf-data' as a temporary solution
// before the update of feedback disclosure to users is done in crbug/934702.
constexpr const char kPerfDataDescription[] =
"perf-data contains performance profiling information about how much time "
"the system spends on various activities (program execution stack traces). "
"This might reveal some information about what system features and "
"resources are being used. The full detail of perf-data can be found in "
"the PerfDataProto protocol buffer message type in the chromium source "
"repository.\n";
#define CMD_KERNEL_MODULE_PARAMS(module_name) \
"cd /sys/module/" #module_name "/parameters 2>/dev/null && grep -sH ^ *"
#define CMD_VM_LOGS(base64_name) \
"nsenter -t1 -m /bin/sh -c 'tail -n+1" \
" /run/daemon-store/crosvm/*/log/" base64_name \
".log.1" \
" /run/daemon-store/crosvm/*/log/" base64_name ".log'"
using Log = LogTool::Log;
constexpr Log::LogType kCommand = Log::kCommand;
constexpr Log::LogType kFile = Log::kFile;
constexpr Log::LogType kGlob = Log::kGlob;
class ArcBugReportLog : public LogTool::Log {
public:
ArcBugReportLog()
: Log(kCommand,
"arc-bugreport",
// This command could take longer than 2 minutes. Give up after 1
// minute since ARC bugreport since P99.94 takes 60 second or less.
"timeout -s KILL 1m /usr/bin/nsenter -t1 -m /usr/sbin/android-sh "
"-c "
"/system/bin/arc-bugreport",
kRoot,
kRoot,
10 * 1024 * 1024 /*10 MiB*/,
LogTool::Encoding::kUtf8) {}
virtual ~ArcBugReportLog() = default;
};
// LogSource stores the information about each log source that
// can be added to |FuncMap| to create tasks to collect logs.
struct LogSource {
// The type of the log.
FeedbackLogType log_type;
// The name of the function that collects the logs.
std::string func_name;
// The callback that collects the logs.
base::OnceCallback<void()> func_callback;
};
// Commands which need special handling. See comments in GetFeedbackLogV3 for
// details.
const Log kNetLog =
Log{kCommand,
"netlog",
"/usr/share/userfeedback/scripts/getmsgs /var/log/net.log",
SandboxedProcess::kDefaultUser,
SandboxedProcess::kDefaultGroup,
Log::kDefaultMaxBytes,
LogTool::Encoding::kUtf8};
const Log kPgmem =
Log{kCommand, "chromeos-pgmem", "/usr/bin/chromeos-pgmem", kRoot, kRoot};
// NOTE: IF YOU ADD AN ENTRY TO THIS LIST, PLEASE:
// * get privacy approval first. Please visit http://go/pwg-cros-reviewer-guide.
// * add a row to http://go/cros-feedback-audit and fill it out.
// (Eventually we'll have a better process, but for now please do this.)
//
// Send an email to cros-feedback-app@ should you have questions.
// clang-format off
const std::array kCommandLogs {
// We need to enter init's mount namespace because it has /home/chronos
// mounted which is where the consent knob lives. We don't have that mount
// in our own mount namespace (by design). https://crbug.com/884249
Log{kCommand, "CLIENT_ID",
"/usr/bin/nsenter -t1 -m /usr/bin/metrics_client -i", kRoot, kDebugfsGroup},
// We consistently use UTC in feedback reports.
Log{kCommand, "LOGDATE", "/bin/date --utc; /bin/date"},
Log{kFile, "amdgpu_gem_info", "/sys/kernel/debug/dri/0/amdgpu_gem_info",
SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kFile, "amdgpu_gtt_mm", "/sys/kernel/debug/dri/0/amdgpu_gtt_mm",
SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kFile, "amdgpu_vram_mm", "/sys/kernel/debug/dri/0/amdgpu_vram_mm",
SandboxedProcess::kDefaultUser, kDebugfsGroup},
// Show du and ls results for dirs under /home/root/*/android-data/data/.
// We need to enter init's mount namespace to access /home/root. Also, we use
// neither ARC container's mount namespace (with android-sh) nor
// /opt/google/containers/android/rootfs/android-data/ so that we can get
// results even when the container is down.
Log{kCommand, "android_app_storage", "/usr/bin/nsenter -t1 -m /bin/sh -c \""
"du -h --one-file-system --max-depth 3 /home/root/*/android-data/data/;"
"find /home/root/*/android-data/data/ -xdev -type d -maxdepth 3 "
"-exec ls -dlZ --time-style='+' {} + | tr -s ' ' '\t' \"",
kRoot, kDebugfsGroup},
Log{kCommand, "arcvm_console_output", "/usr/bin/vm_pstore_dump", "crosvm",
"crosvm", Log::kDefaultMaxBytes, LogTool::Encoding::kAutodetect,
true /* access_root_mount_ns */},
Log{kCommand, "atmel_tp_deltas",
"/opt/google/touch/scripts/atmel_tools.sh tp d", kRoot, kRoot},
Log{kCommand, "atmel_tp_refs",
"/opt/google/touch/scripts/atmel_tools.sh tp r", kRoot, kRoot},
Log{kCommand, "atmel_ts_deltas",
"/opt/google/touch/scripts/atmel_tools.sh ts d", kRoot, kRoot},
Log{kCommand, "atmel_ts_refs",
"/opt/google/touch/scripts/atmel_tools.sh ts r", kRoot, kRoot},
Log{kCommand, "audit_log", "/usr/libexec/debugd/helpers/audit_log_filter",
kRoot, kDebugfsGroup},
Log{kCommand, "bios_log", "cat /sys/firmware/log "
"/proc/device-tree/chosen/ap-console-buffer 2>/dev/null"},
Log{kCommand, "bios_stacked_times", "cbmem -S", kRoot, kRoot},
// Slow or non-responsive block devices could cause this command to stall. Use
// a timeout to prevent this command from blocking log fetching. This command
// is expected to take O(100ms) in the normal case.
Log{kCommand, "blkid", "timeout -s KILL 5s /sbin/blkid", kRoot, kRoot},
Log{kCommand, "bootstat_summary", "/usr/bin/bootstat_summary",
SandboxedProcess::kDefaultUser, SandboxedProcess::kDefaultGroup,
Log::kDefaultMaxBytes, LogTool::Encoding::kAutodetect,
true /* access_root_mount_ns */},
// Ym9yZWFsaXM= is base64 encoded "borealis", the hardcoded VM name.
Log{kCommand, "borealis_crosvm.log", CMD_VM_LOGS("Ym9yZWFsaXM="),
kRoot, kRoot},
Log{kCommand, "bt_usb_disconnects",
"/usr/libexec/debugd/helpers/bt_usb_disconnect_helper",
SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kFile, "buddyinfo", "/proc/buddyinfo"},
Log{kCommand, "cbi_info", "/usr/share/userfeedback/scripts/cbi_info", kRoot,
kRoot},
kPgmem,
// There might be more than one record, so grab them all.
// Plus, for <linux-3.19, it's named "console-ramoops", but for newer
// versions, it's named "console-ramoops-#".
Log{kGlob, "console-ramoops", "/sys/fs/pstore/console-ramoops*",
SandboxedProcess::kDefaultUser, kPstoreAccessGroup },
Log{kFile, "cpuinfo", "/proc/cpuinfo"},
Log{kFile, "cr50_version", "/var/cache/cr50-version"},
Log{kFile, "cros_ec_panicinfo", "/sys/kernel/debug/cros_ec/panicinfo",
SandboxedProcess::kDefaultUser, kDebugfsGroup, Log::kDefaultMaxBytes,
LogTool::Encoding::kBase64},
Log{kCommand, "cros_ec_pdinfo",
"for port in 0 1 2 3 4 5 6 7 8; do "
"echo \"-----------\"; "
"ectool typecstatus \"${port}\" 2>/dev/null || break; "
"echo \"Port C${port} SOP Discovery\"; "
"ectool typecdiscovery \"${port}\" 0 2>/dev/null || continue; "
"echo \"Port C${port} SOP' Discovery\"; "
"ectool typecdiscovery \"${port}\" 1 2>/dev/null || continue; "
"done", kRoot, kRoot},
Log{kCommand, "cros_fp_panicinfo", "ectool --name=cros_fp panicinfo",
kRoot, kRoot},
Log{kCommand, "cros_tp console", "/usr/sbin/ectool --name=cros_tp console",
kRoot, kRoot},
Log{kCommand, "cros_tp frame", "/usr/sbin/ectool --name=cros_tp tpframeget",
kRoot, kRoot},
Log{kFile, "cros_tp version", "/sys/class/chromeos/cros_tp/version"},
Log{kCommand, "crosid", "/usr/bin/crosid -v"},
Log{kCommand, "crostini", "/usr/bin/cicerone_client --get_info"},
// dGVybWluYQ== == "termina", the default Crostini VM name. There may be other
// Crostini VMs, but we don't know their names in debugd and don't want to
// collect logs for non-Crostini VMs. See also b/245504047.
Log{kCommand, "crostini_crosvm.log", CMD_VM_LOGS("dGVybWluYQ=="),
kRoot, kRoot},
// dmesg: add full timestamps to dmesg to match other logs.
// 'dmesg' needs CAP_SYSLOG.
Log{kCommand, "dmesg", "TZ=UTC /bin/dmesg --raw --time-format iso",
kRoot, kRoot},
Log{kGlob, "drm_gem_objects", "/sys/kernel/debug/dri/?/gem",
SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kGlob, "drm_state", "/sys/kernel/debug/dri/?/state",
SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kFile, "drm_trace", "/sys/kernel/tracing/instances/drm/trace",
SandboxedProcess::kDefaultUser, kDebugfsGroup, Log::kDefaultMaxBytes,
LogTool::Encoding::kUtf8},
// TODO(seanpaul): Once we've finished moving over to the upstream tracefs
// implementation, remove drm_trace_legacy. Tracked in
// b/163580546.
Log{kFile, "drm_trace_legacy", "/sys/kernel/debug/dri/trace",
SandboxedProcess::kDefaultUser, kDebugfsGroup, Log::kDefaultMaxBytes,
LogTool::Encoding::kUtf8},
Log{kCommand, "edid-decode",
"for f in /sys/class/drm/card?-*/edid; do "
"echo \"----------- ${f}\"; "
// edid-decode's stderr output is redundant, so silence it.
"edid-decode --skip-hex-dump \"${f}\" 2>/dev/null; "
"done"},
Log{kCommand, "folder_size_dump",
"/usr/libexec/debugd/helpers/folder_size_dump --system",
kRoot, kRoot, 1 * 1024 * 1024 /* 1 MiB*/, LogTool::Encoding::kUtf8, true},
Log{kCommand, "folder_size_dump_user",
"/usr/libexec/debugd/helpers/folder_size_dump --user",
kRoot, kRoot, 1 * 1024 * 1024 /* 1 MiB*/, LogTool::Encoding::kUtf8, true},
Log{kCommand, "font_info", "/usr/share/userfeedback/scripts/font_info"},
Log{kGlob, "framebuffer", "/sys/kernel/debug/dri/?/framebuffer",
SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kCommand, "fwupd_state",
"/usr/bin/fwupdmgr get-devices --json | sed -e '/\"Serial\" :/d' "
"-e '/\"Version\" :/s/\\./:/g'",
kRoot, kRoot},
Log{kCommand, "fwupd_version", "/usr/bin/fwupdmgr --version", kRoot, kRoot},
Log{kCommand, "hardware_class", "/usr/bin/crossystem hwid"},
Log{kFile, "hardware_verification_report",
"/var/cache/hardware_verifier.result"},
Log{kCommand, "hostname", "/bin/hostname"},
Log{kCommand, "hwsec_status", "/usr/sbin/hwsec_status"},
Log{kCommand, "i915_error_state",
"/usr/bin/xz -c /sys/kernel/debug/dri/0/i915_error_state 2>/dev/null",
SandboxedProcess::kDefaultUser, kDebugfsGroup, Log::kDefaultMaxBytes,
LogTool::Encoding::kBase64},
// TODO(b/344690913): remove redundant encoded i915_error_state upload.
Log{kCommand, "i915_error_state_decoded",
"command -v /usr/bin/aubinator_error_decode 1>/dev/null && "
"((/usr/bin/aubinator_error_decode /sys/kernel/debug/dri/0/i915_error_state"
" | /usr/bin/xz -c) 2>/dev/null)",
SandboxedProcess::kDefaultUser, kDebugfsGroup, Log::kDefaultMaxBytes,
LogTool::Encoding::kBase64},
Log{kFile, "i915_gem_gtt", "/sys/kernel/debug/dri/0/i915_gem_gtt",
SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kFile, "i915_gem_objects", "/sys/kernel/debug/dri/0/i915_gem_objects",
SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kCommand, "ifconfig", "/bin/ifconfig -a"},
Log{kFile, "input_devices", "/proc/bus/input/devices"},
// Hardware capabilities of the wiphy device.
Log{kFile, "interrupts", "/proc/interrupts"},
Log{kCommand, "iw_list", "/usr/sbin/iw list"},
#if USE_IWLWIFI_DUMP
Log{kCommand, "iwlmvm_module_params", CMD_KERNEL_MODULE_PARAMS(iwlmvm)},
Log{kCommand, "iwlwifi_module_params", CMD_KERNEL_MODULE_PARAMS(iwlwifi)},
#endif // USE_IWLWIFI_DUMP
Log{kCommand, "kbmcu_info", "ectool --device 18d1:5022 version",
kRoot, kRoot},
Log{kCommand, "kbmcu_log", "ectool --device 18d1:5022 console",
kRoot, kRoot},
Log{kGlob, "kernel-crashes", "/var/spool/crash/kernel.*.kcrash",
SandboxedProcess::kDefaultUser, "crash-access"},
Log{kCommand, "lpstat", "/usr/bin/lpstat -l -r -v -a -p -o",
kLpAdmin, kLpGroup},
Log{kCommand, "lsblk", "timeout -s KILL 5s lsblk -a", kRoot, kRoot,
Log::kDefaultMaxBytes, LogTool::Encoding::kAutodetect,
true /* access_root_mount_ns */},
Log{kCommand, "lsmod", "lsmod"},
Log{kCommand, "lsusb", "lsusb -tvv"},
Log{kCommand, "lsusb_verbose", "lsusb --verbose", kRoot, kRoot},
Log{kFile, "ltr_show", "/sys/kernel/debug/pmc_core/ltr_show",
SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kCommand, "lvs", "lvs -a --units=m", kRoot, kRoot,
1 * 1024 * 1024 /* 1 MiB */, LogTool::Encoding::kUtf8, true},
Log{kFile, "mali_memory", "/sys/kernel/debug/mali0/gpu_memory",
SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kFile, "meminfo", "/proc/meminfo"},
Log{kGlob, "mmc_err_stats", "/sys/kernel/debug/mmc[0-9]/err_stats",
kRoot, kRoot},
Log{kCommand, "modetest",
"(modetest; modetest -M evdi; modetest -M udl) | "
"/usr/libexec/debugd/helpers/modetest_helper",
kRoot, kRoot},
Log{kFile, "mountinfo", "/proc/1/mountinfo"},
Log{kFile, "nvmap_iovmm", "/sys/kernel/debug/nvmap/iovmm/allocations",
SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kCommand, "oemdata", "/usr/share/cros/oemdata.sh", kRoot, kRoot},
Log{kFile, "package_cstate_show", "/sys/kernel/debug/pmc_core/"
"package_cstate_show", SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kFile, "pagetypeinfo", "/proc/pagetypeinfo", kRoot},
Log{kFile, "pch_ip_power_gating_status", "/sys/kernel/debug/pmc_core/"
"pch_ip_power_gating_status",
SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kCommand, "pchg_info", "/usr/share/userfeedback/scripts/pchg_info",
kRoot, kRoot},
Log{kFile, "platform_identity_customization_id",
"/run/chromeos-config/v1/identity/customization-id"},
Log{kFile, "platform_identity_model", "/run/chromeos-config/v1/name"},
Log{kFile, "platform_identity_name",
"/run/chromeos-config/v1/identity/platform-name"},
Log{kFile, "platform_identity_sku",
"/run/chromeos-config/v1/identity/sku-id"},
Log{kFile, "platform_identity_whitelabel_tag",
"/run/chromeos-config/v1/identity/whitelabel-tag"},
Log{kCommand, "power_supply_info", "/usr/bin/power_supply_info",
kRoot, kRoot},
Log{kCommand, "power_supply_sysfs", "/usr/bin/print_sysfs_power_supply_data"},
Log{kCommand, "ps", "/bin/ps auxZ"},
Log{kCommand, "pvs", "pvs --all --readonly --reportformat json -o pv_all",
kRoot, kRoot, 1 * 1024 * 1024 /* 1 MiB*/, LogTool::Encoding::kUtf8, true},
Log{kGlob, "qcom_fw_info", "/sys/kernel/debug/qcom_socinfo/*/*",
SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kCommand, "segmentation_feature_level",
"/usr/sbin/feature_check --feature_level 2>/dev/null", kRoot, kRoot},
Log{kCommand, "segmentation_scope_level",
"/usr/sbin/feature_check --scope_level 2>/dev/null", kRoot, kRoot},
Log{kCommand, "sensor_info", "/usr/share/userfeedback/scripts/sensor_info"},
// /proc/slabinfo is owned by root and has 0400 permission.
Log{kFile, "slabinfo", "/proc/slabinfo", kRoot, kRoot},
Log{kFile, "stateful_trim_data", "/var/lib/trim/stateful_trim_data"},
Log{kFile, "stateful_trim_state", "/var/lib/trim/stateful_trim_state"},
Log{kFile, "substate_live_status_registers", "/sys/kernel/debug/pmc_core/"
"substate_live_status_registers",
SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kFile, "substate_residencies", "/sys/kernel/debug/pmc_core/"
"substate_residencies", SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kFile, "substate_status_registers", "/sys/kernel/debug/pmc_core/"
"substate_status_registers", SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kCommand, "swap_info",
"dbus-send --system --print-reply --fixed"
" --dest=org.chromium.SwapManagement /org/chromium/SwapManagement"
" org.chromium.SwapManagement.SwapStatus",
kRoot, kRoot},
Log{kCommand, "system_log_stats",
"echo 'BLOCK_SIZE=1024'; "
"find /var/log/ -type f -exec du --block-size=1024 {} + | sort -n -r",
kRoot, kRoot},
Log{kCommand, "threads",
"/bin/ps -T axo pid,ppid,spid,pcpu,ni,stat,time,comm"},
Log{kCommand, "top memory",
"/usr/bin/top -o \"+%MEM\" -w128 -bcn 1 | head -n 57"},
Log{kCommand, "top thread", "/usr/bin/top -Hbc -w128 -n 1 | head -n 40"},
Log{kFile, "touch_fw_version", "/run/touch-updater/firmware-versions"},
// Type-C data from the type-c connector class.
Log{kCommand, "typec_connector_class",
"/usr/libexec/debugd/helpers/typec_connector_class_helper"},
// typecd logs average around 56K.
Log{kCommand, "uname", "/bin/uname -a"},
Log{kCommand, "uptime", "/usr/bin/cut -d' ' -f1 /proc/uptime"},
Log{kCommand, "usb4 devices",
"/usr/libexec/debugd/helpers/usb4_devinfo_helper", kRoot, kDebugfsGroup},
Log{kFile, "vmstat", "/proc/vmstat"},
Log{kFile, "wakeup_sources", "/sys/kernel/debug/wakeup_sources",
SandboxedProcess::kDefaultUser, kDebugfsGroup, Log::kDefaultMaxBytes,
LogTool::Encoding::kUtf8},
Log{kCommand, "zram block device stat names",
"echo read_ios read_merges read_sectors read_ticks write_ios "
"write_merges write_sectors write_ticks in_flight io_ticks "
"time_in_queue discard_ios dicard_merges discard_sectors discard_ticks "
"flush_ios flush_ticks"},
Log{kFile, "zram block device stat values", "/sys/block/zram0/stat"},
Log{kCommand, "zram new stats names",
"echo orig_size compr_size used_total limit used_max zero_pages migrated"},
Log{kFile, "zram new stats values", "/sys/block/zram0/mm_stat"},
// Stuff pulled out of the original list. These need access to the running X
// session, which we'd rather not give to debugd, or return info specific to
// the current session (in the setsid(2) sense), which is not useful for
// debugd
// Log{kCommand, "env", "set"},
// Log{kCommand, "setxkbmap", "/usr/bin/setxkbmap -print -query"},
// Log{kCommand, "xrandr", "/usr/bin/xrandr --verbose}
};
// clang-format
// NOTE: IF YOU ADD AN ENTRY TO THIS LIST, PLEASE:
// * get privacy approval first. Please visit http://go/pwg-cros-reviewer-guide.
// * add a row to http://go/cros-feedback-audit and fill it out.
// (Eventually we'll have a better process, but for now please do this.)
//
// Send an email to cros-feedback-app@ should you have questions.
// clang-format off
const std::array kCommandLogsVerbose{
// PCI config space accesses are limited without CAP_SYS_ADMIN.
Log{kCommand, "lspci_verbose", "/usr/bin/lspci -vvvnn", kRoot, kRoot},
// Same as drm_trace, but a larger log. Caller should trim it as needed.
Log{kFile, "drm_trace_verbose", "/sys/kernel/tracing/instances/drm/trace",
SandboxedProcess::kDefaultUser, kDebugfsGroup, 10 * 1024 * 1024,
LogTool::Encoding::kUtf8},
};
// Logs which should appear in chrome://system but not in feedback reports.
const std::array kCommandLogsShort{
Log{kCommand, "lspci", "/usr/bin/lspci"},
};
// Extra logs are logs such as netstat and logcat which should appear in
// chrome://system but not in feedback reports. Open sockets may have privacy
// implications, and logcat is already incorporated via arc-bugreport.
const std::array kExtraLogs {
Log{kCommand, "logcat",
"/usr/bin/nsenter -t1 -m /usr/sbin/android-sh -c '/system/bin/logcat -d'",
kRoot, kRoot, Log::kDefaultMaxBytes, LogTool::Encoding::kUtf8},
#if USE_CELLULAR
Log{kCommand, "mm-esim-status", "/usr/bin/modem esim status"},
Log{kCommand, "mm-status", "/usr/bin/modem status"},
#endif // USE_CELLULAR
// --processes requires root.
Log{kCommand, "netstat",
"/sbin/ss --all --query inet --numeric --processes", kRoot, kRoot},
Log{kCommand, "network-devices", "/usr/bin/connectivity show devices"},
Log{kCommand, "network-services", "/usr/bin/connectivity show services"},
};
// clang-format on
// NOTE: IF YOU ADD AN ENTRY TO THIS LIST, PLEASE:
// * get privacy approval first. Please visit http://go/pwg-cros-reviewer-guide.
// * add a row to http://go/cros-feedback-audit and fill it out.
// (Eventually we'll have a better process, but for now please do this.)
//
// Send an email to cros-feedback-app@ should you have questions.
// clang-format off
const std::array kFeedbackLogs {
Log{kFile, "amd_pmc_idlemask", "/sys/kernel/debug/amd_pmc/amd_pmc_idlemask",
SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kFile, "amd_s0ix_stats", "/sys/kernel/debug/amd_pmc/s0ix_stats",
SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kFile, "amd_smu_fw_info", "/sys/kernel/debug/amd_pmc/smu_fw_info",
SandboxedProcess::kDefaultUser, kDebugfsGroup},
Log{kCommand, "amd_stb", "hexdump -e '2/4 \"%08x \" \"\n\"' "
"/sys/kernel/debug/amd_pmc/stb_read",
kRoot, kRoot},
Log{kCommand, "arcvm_psi", "/usr/bin/nsenter -t1 -m /usr/sbin/android-sh -c "
"'cat /proc/pressure/memory'", kRoot, kRoot, Log::kDefaultMaxBytes,
LogTool::Encoding::kUtf8},
Log{kCommand, "arcvm_zram_mm_stat", "/usr/bin/nsenter -t1 -m "
"/usr/sbin/android-sh -c 'cat /sys/block/zram0/mm_stat'", kRoot, kRoot},
Log{kCommand, "arcvm_zram_stat", "/usr/bin/nsenter -t1 -m "
"/usr/sbin/android-sh -c 'cat /sys/block/zram0/stat'", kRoot, kRoot},
Log{kCommand, "borealis_fossilize_wrap_log", "timeout -s KILL 5s "
"/usr/bin/borealis-sh -- /usr/bin/get_feedback_file.sh "
"/tmp/fossilize-wrap-log.txt",
kRoot, kRoot},
Log{kCommand, "borealis_frames", "timeout -s KILL 5s /usr/bin/borealis-sh "
"-- /usr/bin/get-frame-log.sh", kRoot, kRoot},
Log{kCommand, "borealis_frames_summary", "timeout -s KILL 5s "
"/usr/bin/borealis-sh -- /usr/bin/get-frame-summary.sh", kRoot, kRoot},
Log{kCommand, "borealis_frames_stats", "timeout -s KILL 5s "
"/usr/bin/borealis-sh -- cat /tmp/sommelier-stats", kRoot, kRoot},
Log{kCommand, "borealis_launch_log", "timeout -s KILL 5s "
"/usr/bin/borealis-sh -- /usr/bin/get_feedback_file.sh /tmp/launch-log.txt",
kRoot, kRoot},
Log{kCommand, "borealis_proton_crash_reports", "timeout -s KILL 5s "
"/usr/bin/borealis-sh -- /usr/bin/get_feedback_file.sh "
"/tmp/proton_crashreports/",
kRoot, kRoot},
Log{kCommand, "borealis_quirks", "timeout -s KILL 5s "
"/usr/bin/borealis-sh -- /usr/bin/print_quirks_configs.sh"
" | head --bytes=10240",
kRoot, kRoot},
Log{kCommand, "borealis_rootfs_reports", "timeout -s KILL 5s "
"/usr/bin/borealis-sh -- /usr/bin/get_rootfs_report.sh", kRoot, kRoot},
Log{kCommand, "borealis_steam_log", "timeout -s KILL 5s "
"/usr/bin/borealis-sh -- /usr/bin/get_feedback_file.sh /tmp/steam-log.txt",
kRoot, kRoot},
Log{kCommand, "borealis_xwindump", "timeout -s KILL 5s /usr/bin/borealis-sh "
"-- /usr/bin/xwindump.py", kRoot, kRoot},
Log{kGlob, "iwlwifi_firmware_version",
"/sys/kernel/debug/iwlwifi/*/iwlmvm/fw_ver", kRoot, kRoot},
Log{kCommand, "iwlwifi_sysasserts",
"croslog --show-cursor=false --identifier=kernel --priority=err"
" --grep='iwlwifi.*ADVANCED_SYSASSERT' --quiet | tail -n 3"},
Log{kCommand, "iwlwifi_sysasserts_count",
"croslog --show-cursor=false --identifier=kernel --priority=err"
" --grep='iwlwifi.*ADVANCED_SYSASSERT' | wc -l"},
#if USE_CELLULAR
Log{kCommand, "mm-esim-status", "/usr/bin/modem esim status_feedback"},
Log{kCommand, "mm-status", "/usr/bin/modem status-feedback"},
#endif // USE_CELLULAR
Log{kCommand, "network-devices",
"/usr/bin/connectivity show-feedback devices"},
Log{kCommand, "network-services",
"/usr/bin/connectivity show-feedback services"},
Log{kFile, "psi_cpu", "/proc/pressure/cpu"},
Log{kFile, "psi_io", "/proc/pressure/io"},
Log{kFile, "psi_memory", "/proc/pressure/memory"},
Log{kCommand, "shill_connection_diagnostic",
"croslog --show-cursor=false --identifier=shill"
" --grep='Connection issue:' --quiet | tail -n 3"},
Log{kCommand, "wifi_connection_attempts",
"croslog --show-cursor=false --identifier=kernel"
" --grep='(authenticate|associate) with' | wc -l"},
Log{kCommand, "wifi_connection_timeouts",
"croslog --show-cursor=false --identifier=kernel"
" --grep='(authentication|association).*timed out' | wc -l"},
Log{kCommand, "wifi_driver_errors",
"croslog --since=-7200 --show-cursor=false --identifier=kernel"
" --priority=err --grep='(iwlwifi|mwifiex|ath10k)' --quiet"},
Log{kCommand, "wifi_driver_errors_count",
"croslog --since=-7200 --show-cursor=false --identifier=kernel"
" --priority=err --grep='(iwlwifi|mwifiex|ath10k)' | wc -l"},
};
// clang-format on
// The log files reside under /var/log/. Logs will be obtained by reading the
// complete files in this list without extracting specific information. Other
// lists (e.g. |kCommandLogs|) may still read /var/log files to search for
// specific information.
//
// NOTE: IF YOU ADD AN ENTRY TO THIS LIST, PLEASE:
// * get privacy approval first. Please visit http://go/pwg-cros-reviewer-guide.
// * add a row to http://go/cros-feedback-audit and fill it out.
// (Eventually we'll have a better process, but for now please do this.)
//
// Send an email to cros-feedback-app@ should you have questions.
// clang-format off
const std::array kVarLogFileLogs {
Log{kFile, "atrus_logs", "/var/log/atrus.log"},
Log{kFile, "auth_failure", "/var/log/tcsd/auth_failure.permanent"},
Log{kFile, "bio_crypto_init.LATEST",
"/var/log/bio_crypto_init/bio_crypto_init.LATEST"},
Log{kFile, "bio_crypto_init.PREVIOUS",
"/var/log/bio_crypto_init/bio_crypto_init.PREVIOUS"},
Log{kFile, "bio_fw_updater.LATEST", "/var/log/biod/bio_fw_updater.LATEST"},
Log{kFile, "bio_fw_updater.PREVIOUS",
"/var/log/biod/bio_fw_updater.PREVIOUS"},
Log{kFile, "biod.LATEST", "/var/log/biod/biod.LATEST"},
Log{kFile, "biod.PREVIOUS", "/var/log/biod/biod.PREVIOUS"},
Log{kFile, "bios_info", "/var/log/bios_info.txt"},
Log{kFile, "bios_times", "/var/log/bios_times.txt"},
Log{kFile, "bluetooth.log", "/var/log/bluetooth.log"},
Log{kFile, "cheets_log", "/var/log/arc.log"},
Log{kFile, "chrome_system_log", "/var/log/chrome/chrome"},
Log{kFile, "chrome_system_log.PREVIOUS", "/var/log/chrome/chrome.PREVIOUS"},
Log{kFile, "clobber-state.log", "/var/log/clobber-state.log"},
Log{kFile, "clobber.log", "/var/log/clobber.log"},
Log{kFile, "cros_ec.log", "/var/log/cros_ec.log",
SandboxedProcess::kDefaultUser, SandboxedProcess::kDefaultGroup,
Log::kDefaultMaxBytes, LogTool::Encoding::kUtf8},
Log{kFile, "cros_ec.previous", "/var/log/cros_ec.previous",
SandboxedProcess::kDefaultUser, SandboxedProcess::kDefaultGroup,
Log::kDefaultMaxBytes, LogTool::Encoding::kUtf8},
Log{kFile, "cros_fp.log", "/var/log/cros_fp.log",
SandboxedProcess::kDefaultUser, SandboxedProcess::kDefaultGroup,
Log::kDefaultMaxBytes, LogTool::Encoding::kUtf8},
Log{kFile, "cros_fp.previous", "/var/log/cros_fp.previous",
SandboxedProcess::kDefaultUser, SandboxedProcess::kDefaultGroup,
Log::kDefaultMaxBytes, LogTool::Encoding::kUtf8},
Log{kFile, "cros_ish.log", "/var/log/cros_ish.log",
SandboxedProcess::kDefaultUser, SandboxedProcess::kDefaultGroup,
Log::kDefaultMaxBytes, LogTool::Encoding::kUtf8},
Log{kFile, "cros_ish.previous", "/var/log/cros_ish.previous",
SandboxedProcess::kDefaultUser, SandboxedProcess::kDefaultGroup,
Log::kDefaultMaxBytes, LogTool::Encoding::kUtf8},
Log{kFile, "cros_scp.log", "/var/log/cros_scp.log",
SandboxedProcess::kDefaultUser, SandboxedProcess::kDefaultGroup,
64 * 1024, LogTool::Encoding::kUtf8},
Log{kFile, "cros_scp.previous", "/var/log/cros_scp.previous",
SandboxedProcess::kDefaultUser, SandboxedProcess::kDefaultGroup,
64 * 1024, LogTool::Encoding::kUtf8},
Log{kGlob, "display-debug", "/var/log/display_debug/*",
kRoot, kRoot,
4 * 1024 * 1024, LogTool::Encoding::kUtf8},
Log{kFile, "ec_info", "/var/log/ec_info.txt"},
Log{kFile, "eventlog", "/var/log/eventlog.txt"},
Log{kFile, "extensions.log", "/var/log/extensions.log"},
Log{kFile, "fwupd_log", "/var/log/fwupd.log"},
Log{kCommand, "gsclog", "/usr/bin/gsclog; cat /var/log/gsc.log", kRoot,
kRoot},
Log{kFile, "hammerd", "/var/log/hammerd.log"},
Log{kFile, "hypervisor.log", "/var/log/hypervisor.log"},
Log{kGlob, "memd clips", "/var/log/memd/memd.clip*"},
Log{kFile, "memd.parameters", "/var/log/memd/memd.parameters"},
Log{kFile, "mount-encrypted", "/var/log/mount-encrypted.log"},
Log{kFile, "nbr_minios_log", "/var/log/minios/minios.log"},
Log{kFile, "nbr_update_engine_log", "/var/log/minios/update_engine.log"},
Log{kFile, "nbr_upstart_log", "/var/log/minios/upstart.log"},
kNetLog,
Log{kFile, "powerd.LATEST", "/var/log/power_manager/powerd.LATEST"},
Log{kFile, "powerd.PREVIOUS", "/var/log/power_manager/powerd.PREVIOUS"},
Log{kFile, "powerd.out", "/var/log/powerd.out"},
Log{kFile, "powerwash_count", "/var/log/powerwash_count"},
Log{kCommand, "secagentd", "tail -n 300 /var/log/secagentd.log"},
Log{kFile, "storage_info", "/var/log/storage_info.txt"},
Log{kCommand, "syslog",
"/usr/share/userfeedback/scripts/getmsgs /var/log/messages"},
Log{kFile, "tlsdate", "/var/log/tlsdate.log"},
Log{kCommand, "tpm-firmware-updater",
"/usr/share/userfeedback/scripts/getmsgs "
"/var/log/tpm-firmware-updater.log"},
Log{kFile, "typecd", "/var/log/typecd.log"},
Log{kFile, "ui_log", "/var/log/ui/ui.LATEST"},
Log{kCommand, "update_engine.log",
"cat $(ls -1tr /var/log/update_engine | tail -5 | sed"
" s.^./var/log/update_engine/.)"},
Log{kFile, "upstart", "/var/log/upstart.log"},
Log{kFile, "verified boot", "/var/log/debug_vboot_noisy.log"},
Log{kFile, "vmlog.1.LATEST", "/var/log/vmlog/vmlog.1.LATEST"},
Log{kFile, "vmlog.1.PREVIOUS", "/var/log/vmlog/vmlog.1.PREVIOUS"},
Log{kFile, "vmlog.LATEST", "/var/log/vmlog/vmlog.LATEST"},
Log{kFile, "vmlog.PREVIOUS", "/var/log/vmlog/vmlog.PREVIOUS"},
Log{kCommand, "vpd_2.0", "/usr/libexec/debugd/helpers/filter_vpd"},
};
// clang-format on
bool IncludeLogType(const std::vector<int32_t>& requested_logs,
FeedbackLogType log_type) {
// Empty requested_logs means include all log types.
return requested_logs.empty() || base::Contains(requested_logs, log_type);
}
// Combine all requested logs whose source is a list of Log into one array.
std::vector<Log> GetRequestedLogItems(
const std::vector<int32_t>& requested_logs) {
std::vector<Log> log_list;
if (IncludeLogType(requested_logs, FeedbackLogType::COMMAND_LOGS)) {
log_list.insert(log_list.end(), kCommandLogs.begin(), kCommandLogs.end());
}
if (IncludeLogType(requested_logs, FeedbackLogType::VERBOSE_COMMAND_LOGS)) {
log_list.insert(log_list.end(), kCommandLogsVerbose.begin(),
kCommandLogsVerbose.end());
}
if (IncludeLogType(requested_logs, FeedbackLogType::FEEDBACK_LOGS)) {
log_list.insert(log_list.end(), kFeedbackLogs.begin(), kFeedbackLogs.end());
}
if (IncludeLogType(requested_logs, FeedbackLogType::VAR_LOG_FILES)) {
log_list.insert(log_list.end(), kVarLogFileLogs.begin(),
kVarLogFileLogs.end());
}
return log_list;
}
// Fills |dictionary| with the contents of the logs in |logs|.
template <std::size_t N>
void GetLogsInDictionary(const std::array<Log, N>& logs,
base::Value::Dict* dictionary) {
for (const Log& log : logs) {
dictionary->Set(log.GetName(), log.GetLogData());
}
}
// Serializes the |dictionary| into the file with the given |fd| in a JSON
// format.
void SerializeLogsAsJSON(const base::Value::Dict& dictionary,
const base::ScopedFD& fd) {
string logs_json;
base::JSONWriter::WriteWithOptions(
dictionary, base::JSONWriter::OPTIONS_PRETTY_PRINT, &logs_json);
base::WriteFileDescriptor(fd.get(), logs_json);
}
template <std::size_t N>
bool GetNamedLogFrom(const string& name,
const std::array<Log, N>& logs,
string* result) {
for (const Log& log : logs) {
if (name == log.GetName()) {
*result = log.GetLogData();
return true;
}
}
*result = "<invalid log name>";
return false;
}
template <std::size_t N>
void GetLogsFrom(const std::array<Log, N>& logs, LogTool::LogMap* map) {
for (const Log& log : logs)
(*map)[log.GetName()] = log.GetLogData();
}
void GetLsbReleaseInfo(LogTool::LogMap* map) {
const base::FilePath lsb_release(kLsbReleasePath);
brillo::KeyValueStore store;
if (!store.Load(lsb_release)) {
// /etc/lsb-release might not be present (cros deploying a new
// configuration or no fields set at all). Just print a debug
// message and continue.
DLOG(INFO) << "Could not load fields from " << lsb_release.value();
} else {
for (const auto& key : store.GetKeys()) {
// The DEVICETYPE from /etc/lsb-release may not be correct on some
// unibuild devices, so filter it out.
if (key != "DEVICETYPE") {
std::string value;
store.GetString(key, &value);
(*map)[key] = value;
}
}
}
}
void GetOsReleaseInfo(LogTool::LogMap* map) {
brillo::OsReleaseReader reader;
reader.Load();
for (const auto& key : reader.GetKeys()) {
std::string value;
reader.GetString(key, &value);
(*map)["os-release " + key] = value;
}
}
bool CompressXzBuffer(const std::vector<uint8_t>& in_buffer,
std::vector<uint8_t>* out_buffer) {
size_t out_size = lzma_stream_buffer_bound(in_buffer.size());
out_buffer->resize(out_size);
size_t out_pos = 0;
lzma_ret ret = lzma_easy_buffer_encode(
LZMA_PRESET_DEFAULT, LZMA_CHECK_CRC64, nullptr, in_buffer.data(),
in_buffer.size(), out_buffer->data(), &out_pos, out_size);
if (ret != LZMA_OK) {
out_buffer->clear();
return false;
}
out_buffer->resize(out_pos);
return true;
}
void GetPerfData(LogTool::LogMap* map, debugd::PerfTool* perf_tool) {
// Collect a Perfetto trace concurrently with perf to avoid adding significant
// extra delay to feedback report generation.
std::unique_ptr<PerfettoTool> perfetto = PerfettoTool::Start();
// Run perf to collect system-wide performance profile when user triggers
// feedback report. Perf runs at sampling frequency of ~500 hz (499 is used
// to avoid sampling periodic system activities), with callstack in each
// sample (-g).
std::vector<std::string> perf_args = {
"perf", "record", "-a", "-g", "-F", "499",
};
std::vector<uint8_t> perf_data;
int32_t status;
if (!perf_tool->GetPerfOutput(kPerfDurationSecs, perf_args, &perf_data,
nullptr, &status, nullptr))
return;
// Retrieve and attach the Perfetto trace.
if (perfetto) {
std::optional<std::string> perfetto_trace = perfetto->Stop();
if (perfetto_trace) {
(*map)["perfetto-data"] = LogTool::EncodeString(
std::move(*perfetto_trace), LogTool::Encoding::kBase64);
}
}
// XZ compress the profile data.
std::vector<uint8_t> perf_data_xz;
if (!CompressXzBuffer(perf_data, &perf_data_xz))
return;
// Base64 encode the compressed data.
std::string perf_data_str(reinterpret_cast<const char*>(perf_data_xz.data()),
perf_data_xz.size());
(*map)["perf-data"] = std::string(kPerfDataDescription) +
LogTool::EncodeString(std::move(perf_data_str),
LogTool::Encoding::kBase64);
}
} // namespace
Log::Log(Log::LogType type,
std::string name,
std::string data,
std::string user,
std::string group,
int64_t max_bytes,
LogTool::Encoding encoding,
bool access_root_mount_ns)
: type_(type),
name_(name),
data_(data),
user_(user),
group_(group),
max_bytes_(max_bytes),
encoding_(encoding),
access_root_mount_ns_(access_root_mount_ns) {}
std::string Log::GetName() const {
return name_;
}
Log::LogType Log::GetType() const {
return type_;
}
LogTool::Encoding Log::GetEncoding() const {
return encoding_;
}
int64_t Log::GetMaxBytes() const {
return max_bytes_;
}
std::string Log::GetLogData() const {
// The reason this code uses a switch statement on a type enum rather than
// using inheritance/virtual dispatch is so that all of the Log objects can
// be constructed statically. Switching to heap allocated subclasses of Log
// makes the code that declares all of the log entries much more verbose
// and harder to understand.
base::expected<std::string, std::string> output;
switch (type_) {
case kCommand:
output = GetCommandLogData();
break;
case kFile:
output = GetFileLogData();
break;
case kGlob:
output = GetGlobLogData();
break;
default:
DCHECK(false) << "unknown log type";
return "<unknown log type>";
}
if (!output.has_value()) {
if (output.error().empty())
return kLogEmpty;
else
return output.error();
}
if (output->empty())
return kLogEmpty;
return LogTool::EncodeString(std::move(*output), encoding_);
}
// TODO(ellyjones): sandbox. crosbug.com/35122
base::expected<std::string, std::string> Log::GetCommandLogData() const {
DCHECK_EQ(type_, kCommand);
if (type_ != kCommand)
return base::unexpected("<log type mismatch>");
std::string tailed_cmdline =
base::StringPrintf("%s | tail -c %" PRId64, data_.c_str(), max_bytes_);
ProcessWithOutput p;
if (minijail_disabled_for_test_)
p.set_use_minijail(false);
if (!user_.empty() && !group_.empty())
p.SandboxAs(user_, group_);
if (access_root_mount_ns_)
p.AllowAccessRootMountNamespace();
// Opt-out of Minijail's default runtime environment, because the seccomp
// policy causes issues on jacuzzi. See b/267050115.
std::vector<std::string> minijail_args{"--no-default-runtime-environment"};
if (!p.Init(minijail_args))
return base::unexpected(kLogNotAvailable);
p.AddArg(kShell);
p.AddStringOption("-c", tailed_cmdline);
if (p.Run())
return base::unexpected(kLogNotAvailable);
std::string output;
p.GetOutput(&output);
return base::ok(output);
}
// static
base::expected<std::string, std::string> Log::GetFileData(
const base::FilePath& path,
int64_t max_bytes,
const std::string& user,
const std::string& group) {
uid_t old_euid = geteuid();
uid_t new_euid = UidForUser(user);
gid_t old_egid = getegid();
gid_t new_egid = GidForGroup(group);
if (new_euid == -1 || new_egid == -1) {
return base::unexpected(kLogNotAvailable);
}
// Make sure to set group first, since if we set user first we lose root
// and therefore the ability to set our effective gid to arbitrary gids.
if (setegid(new_egid)) {
PLOG(ERROR) << "Failed to set effective group id to " << new_egid;
return base::unexpected(kLogNotAvailable);
}
if (seteuid(new_euid)) {
PLOG(ERROR) << "Failed to set effective user id to " << new_euid;
if (setegid(old_egid))
PLOG(ERROR) << "Failed to restore effective group id to " << old_egid;
return base::unexpected(kLogNotAvailable);
}
base::expected<std::string, std::string> result;
// Handle special files that don't properly report length/allow lseek.
if (base::FilePath("/dev").IsParent(path) ||
base::FilePath("/proc").IsParent(path) ||
base::FilePath("/sys").IsParent(path)) {
std::string contents;
if (!base::ReadFileToString(path, &contents)) {
result = base::unexpected(kLogNotAvailable);
} else {
if (contents.size() > max_bytes)
contents.erase(0, contents.size() - max_bytes);
result = base::ok(std::move(contents));
}
} else {
base::File file(path, base::File::FLAG_OPEN | base::File::FLAG_READ);
if (!file.IsValid()) {
result = base::unexpected(kLogNotAvailable);
} else {
int64_t length = file.GetLength();
if (length > max_bytes) {
file.Seek(base::File::FROM_END, -max_bytes);
length = max_bytes;
}
std::vector<char> buf(length);
int read = file.ReadAtCurrentPos(buf.data(), buf.size());
if (read < 0) {
PLOG(ERROR) << "Could not read from file " << path.value();
result = base::unexpected(kLogNotAvailable);
} else {
result = base::ok(std::string(buf.begin(), buf.begin() + read));
}
}
}
// Make sure we restore our old euid/egid before returning.
if (seteuid(old_euid))
PLOG(ERROR) << "Failed to restore effective user id to " << old_euid;
if (setegid(old_egid))
PLOG(ERROR) << "Failed to restore effective group id to " << old_egid;
return result;
}
base::expected<std::string, std::string> Log::GetFileLogData() const {
DCHECK_EQ(type_, kFile);
if (type_ != kFile)
return base::unexpected("<log type mismatch>");
return GetFileData(base::FilePath(data_), max_bytes_, user_, group_);
}
base::expected<std::string, std::string> Log::GetGlobLogData() const {
DCHECK_EQ(type_, kGlob);
if (type_ != kGlob)
return base::unexpected("<log type mismatch>");
// NB: base::FileEnumerator requires a directory to walk, and a pattern to
// match against each result. Here we accept full paths with globs in them.
glob_t g;
// NB: Feel free to add GLOB_BRACE if a user comes up.
int gret = glob(data_.c_str(), 0, nullptr, &g);
if (gret == GLOB_NOMATCH) {
globfree(&g);
return base::unexpected("<no matches>");
} else if (gret) {
globfree(&g);
PLOG(ERROR) << "glob " << data_ << " failed";
return base::unexpected(kLogNotAvailable);
}
// The results array will hold 2 entries per file: the filename, and the
// results of reading that file.
size_t output_size = 0;
std::vector<std::string> results;
results.reserve(g.gl_pathc * 2);
for (size_t pathc = 0; pathc < g.gl_pathc; ++pathc) {
const base::FilePath path(g.gl_pathv[pathc]);
base::expected<std::string, std::string> result =
GetFileData(path, max_bytes_, user_, group_);
std::string contents;
if (result.has_value())
contents = result.value();
else
contents = result.error();
// NB: The 3 represents the bytes we add in the output string below.
output_size += path.value().size() + contents.size() + 3;
results.push_back(path.value());
results.push_back(contents);
}
globfree(&g);
// Combine the results into a single string. We have a header with the
// filename followed by that file's contents. Very basic format.
std::string output;
output.reserve(output_size);
for (auto iter = results.begin(); iter != results.end(); ++iter) {
output += *iter + ":\n";
++iter;
output += *iter + "\n";
}
return base::ok(output);
}
void Log::DisableMinijailForTest() {
minijail_disabled_for_test_ = true;
}
// static
uid_t Log::UidForUser(const std::string& user) {
struct passwd entry;
struct passwd* result;
std::vector<char> buf(1024);
getpwnam_r(user.c_str(), &entry, &buf[0], buf.size(), &result);
if (!result) {
LOG(ERROR) << "User not found: " << user;
return -1;
}
return entry.pw_uid;
}
// static
gid_t Log::GidForGroup(const std::string& group) {
struct group entry;
struct group* result;
std::vector<char> buf(1024);
getgrnam_r(group.c_str(), &entry, &buf[0], buf.size(), &result);
if (!result) {
LOG(ERROR) << "Group not found: " << group;
return -1;
}
return entry.gr_gid;
}
bool Log::StartToGetLogData(std::unique_ptr<SandboxedProcess>& child_proc,
const base::FilePath& output_file_name) const {
if (!user_.empty() && !group_.empty())
child_proc->SandboxAs(user_, group_);
if (access_root_mount_ns_)
child_proc->AllowAccessRootMountNamespace();
// Opt-out of Minijail's default runtime environment, because the seccomp
// policy causes issues on jacuzzi. See b/267050115.
std::vector<std::string> minijail_args{"--no-default-runtime-environment"};
if (!child_proc->Init(minijail_args))
return false;
child_proc->AddArg(kShell);
child_proc->AddStringOption("-c", data_);
child_proc->RedirectOutput(output_file_name);
return child_proc->Start();
}
LogTool::ParallelLogCollector::ParallelLogCollector(
base::TimeDelta max_wait_time)
: max_parallelism_(std::max(2, base::SysInfo::NumberOfProcessors())),
deadline_(base::TimeTicks::Now() + max_wait_time) {}
bool LogTool::ParallelLogCollector::StartGetLogs(
const std::vector<Log>& log_list) {
DLOG(INFO) << "StartGetLogs, size=" << log_list.size();
if (!temp_dir_.CreateUniqueTempDir()) {
LOG(ERROR) << "Failed to create a temporary directory";
return false;
}
// Specify the temp file to store log data for each log. The mapping is needed
// when reading them later.
for (const Log& log : log_list) {
// The temp file to store the log content.
const base::FilePath output_file =
temp_dir_.GetPath().Append(log.GetName());
file_log_map_.emplace(output_file, log);
}
task_controller_pid_ = fork();
switch (task_controller_pid_) {
case -1:
// Fork failed.
PLOG(ERROR) << "StartGetLogs: fork failure";
return false;
case 0:
// Child process.
CollectLogs(file_log_map_, deadline_, max_parallelism_);
exit(EXIT_SUCCESS);
default:
// Parent process.
VLOG(1) << "StartGetLogs, task_controller_pid=" << task_controller_pid_;
break;
}
return true;
}
void LogTool::ParallelLogCollector::EndGetLogs(base::Value::Dict* dict) {
const base::TimeDelta sleep_interval = base::Seconds(1);
// Wait for the controller to finish or until the deadline.
int status;
while (base::TimeTicks::Now() < deadline_) {
if (waitpid(task_controller_pid_, &status, WNOHANG) > 0) {
break;
}
sleep(sleep_interval.InSeconds());
}
for (auto const& pair : file_log_map_) {
const Log& log = pair.second;
std::string data;
if (base::ReadFileToString(pair.first, &data)) {
if (data.empty()) {
dict->Set(pair.second.GetName(), kLogEmpty);
} else {
// If the log size exceeds the specified limit, tail it.
if (data.size() > log.GetMaxBytes()) {
data.erase(0, data.size() - log.GetMaxBytes());
}
// For types other than kCommand the output has already been encoded.
if (log.GetType() == kCommand) {
std::string encoded_data =
LogTool::EncodeString(std::move(data), log.GetEncoding());
dict->Set(log.GetName(), std::move(encoded_data));
} else {
dict->Set(log.GetName(), std::move(data));
}
}
} else {
LOG(ERROR) << "EndGetLogs: failed to read file=" << pair.first.value()
<< ", log=" << log.GetName();
dict->Set(log.GetName(), kLogNotAvailable);
}
}
}
void LogTool::ParallelLogCollector::CollectLogs(
const std::map<base::FilePath, Log>& filepath_logs,
const base::TimeTicks& deadline,
const size_t max_parallelism) {
VLOG(1) << "CollectLogs: max_parallelism=" << max_parallelism;
// Keep track of all processes created in this method.
std::vector<std::unique_ptr<brillo::Process>> child_processes;
// Track created pids and their corresponding log names.
std::unordered_map<pid_t, const std::string&> running_child_pids_;
pid_t child_pid;
int status;
// Time to wait before checking any task has completed. Most tasks are quick.
const base::TimeDelta poll_interval = base::Milliseconds(20);
auto task_it = filepath_logs.begin();
while (task_it != filepath_logs.end() && base::TimeTicks::Now() < deadline) {
child_pid = waitpid(-1, &status, WNOHANG);
if (child_pid > 0) {
// A child process has exited.
running_child_pids_.erase(child_pid);
}
// Limit # of concurrent tasks to be <= max_parallelism.
if (running_child_pids_.size() >= max_parallelism) {
usleep(poll_interval.InMicroseconds());
// Go back and check whether any tasks have completed.
continue;
}
// Start to process a new task.
const Log& log = task_it->second;
const base::FilePath& output_file = task_it->first;
auto sub_process = std::make_unique<SandboxedProcess>();
switch (log.GetType()) {
case Log::kCommand:
if (log.StartToGetLogData(sub_process, output_file)) {
running_child_pids_.emplace(sub_process->pid(), log.GetName());
child_processes.push_back(std::move(sub_process));
}
break;
case Log::kFile:
case Log::kGlob:
child_pid = fork();
switch (child_pid) {
case -1:
PLOG(ERROR) << "CollectLogs: fork failure, log=" << log.GetName();
// Fork failed. Skip this log. When the system is having serious
// problems such that fork keeps failing, then the loop will exit
// quickly.
break;
case 0:
// Child process.
base::WriteFile(output_file, log.GetLogData());
exit(EXIT_SUCCESS);
default:
// Parent process.
running_child_pids_.emplace(child_pid, log.GetName());
break;
}
break;
}
++task_it;
}
// Wait for started tasks to complete or timeout.
while (!running_child_pids_.empty() && base::TimeTicks::Now() < deadline) {
child_pid = waitpid(-1, &status, WNOHANG);
if (child_pid > 0) {
// A child process has exited.
running_child_pids_.erase(child_pid);
} else {
usleep(poll_interval.InMicroseconds());
}
}
// Log tasks not started yet.
for (; task_it != filepath_logs.end(); task_it++) {
LOG(WARNING) << "CollectLogs: not started, Log="
<< task_it->second.GetName();
}
// Log tasks started but not finished on time.
for (auto& p : child_processes) {
if (base::Contains(running_child_pids_, p->pid())) {
LOG(WARNING) << "CollectLogs: timed out, Log="
<< running_child_pids_.at(p->pid());
} else {
// Releases exited processes.
p->Release();
}
}
}
LogTool::LogTool(
scoped_refptr<dbus::Bus> bus,
std::unique_ptr<org::chromium::CryptohomeMiscInterfaceProxyInterface>
cryptohome_proxy,
std::unique_ptr<LogTool::Log> arc_bug_report_log,
const base::FilePath& daemon_store_base_dir)
: bus_(bus),
cryptohome_proxy_(std::move(cryptohome_proxy)),
arc_bug_report_log_(std::move(arc_bug_report_log)),
daemon_store_base_dir_(daemon_store_base_dir) {}
LogTool::LogTool(scoped_refptr<dbus::Bus> bus, const bool perf_logging)
: LogTool(
bus,
std::make_unique<org::chromium::CryptohomeMiscInterfaceProxy>(bus),
std::make_unique<ArcBugReportLog>(),
base::FilePath(kDaemonStoreBaseDir)) {
perf_logging_ = perf_logging;
}
bool LogTool::IsUserHashValid(const std::string& userhash) {
return brillo::cryptohome::home::IsSanitizedUserName(userhash) &&
base::PathExists(daemon_store_base_dir_.Append(userhash));
}
void LogTool::CreateConnectivityReport(bool wait_for_results) {
// Perform ConnectivityTrial to report connection state in feedback log.
auto shill = std::make_unique<org::chromium::flimflam::ManagerProxy>(bus_);
// Give the connection trial time to test the connection and log the results
// before collecting the logs for feedback.
// TODO(silberst): Replace the simple approach of a single timeout with a more
// coordinated effort.
if (shill && shill->CreateConnectivityReport(nullptr) && wait_for_results)
sleep(kConnectionTesterTimeoutSeconds);
}
std::optional<string> LogTool::GetLog(const string& name) {
string result;
if (GetNamedLogFrom(name, kCommandLogs, &result) ||
GetNamedLogFrom(name, kVarLogFileLogs, &result) ||
GetNamedLogFrom(name, kCommandLogsShort, &result) ||
GetNamedLogFrom(name, kExtraLogs, &result) ||
GetNamedLogFrom(name, kFeedbackLogs, &result) ||
GetNamedLogFrom(name, kCommandLogsVerbose, &result)) {
return std::make_optional(result);
}
return std::nullopt;
}
LogTool::LogMap LogTool::GetAllLogs() {
Stopwatch sw("Perf.GetAllLogs", perf_logging_, /*report_lap_to_uma=*/false);
CreateConnectivityReport(false);
LogMap result;
GetLogsFrom(kCommandLogsShort, &result);
GetLogsFrom(kCommandLogs, &result);
GetLogsFrom(kVarLogFileLogs, &result);
GetLogsFrom(kExtraLogs, &result);
GetLsbReleaseInfo(&result);
GetOsReleaseInfo(&result);
return result;
}
LogTool::LogMap LogTool::GetAllDebugLogs() {
Stopwatch sw("Perf.GetAllDebugLogs", perf_logging_,
/*report_lap_to_uma=*/false);
CreateConnectivityReport(true);
LogMap result;
GetLogsFrom(kCommandLogsShort, &result);
GetLogsFrom(kCommandLogs, &result);
GetLogsFrom(kVarLogFileLogs, &result);
GetLogsFrom(kExtraLogs, &result);
result[arc_bug_report_log_->GetName()] = GetArcBugReport("", nullptr);
GetLsbReleaseInfo(&result);
GetOsReleaseInfo(&result);
return result;
}
template <std::size_t N>
std::vector<std::string> GetTitlesFrom(const std::array<Log, N>& logs) {
std::vector<std::string> result;
for (const Log& log : logs) {
result.push_back(log.GetName());
}
return result;
}
std::vector<std::vector<std::string>> GetAllDebugTitlesForTest() {
std::vector<std::vector<std::string>> result;
result.push_back(GetTitlesFrom(kCommandLogsShort));
result.push_back(GetTitlesFrom(kCommandLogs));
result.push_back(GetTitlesFrom(kVarLogFileLogs));
result.push_back(GetTitlesFrom(kExtraLogs));
return result;
}
void LogTool::GetFeedbackLogs(const base::ScopedFD& fd,
const std::string& username,
PerfTool* perf_tool,
const std::vector<int32_t>& requested_logs) {
// Create and start the stopwatch used for measuring performance. The same
// metric is used so we can compare the performance in A/B testing easily.
// We do not record metrics for subtasks (i.e laps) since most of them are
// broken into smaller unit and being collected in parallel.
Stopwatch sw("Perf.GetBigFeedbackLogs", perf_logging_,
/*report_lap_to_uma=*/false);
const bool include_connectivity_report =
IncludeLogType(requested_logs, FeedbackLogType::CONNECTIVITY_REPORT);
const base::TimeTicks connectivity_report_start_at = base::TimeTicks::Now();
if (include_connectivity_report) {
// The net.log depends on this call to generate more logs. As an
// optimization, postpone waiting for results until other tasks have
// completed.
CreateConnectivityReport(/*wait_for_results=*/false);
}
// All logs will eventually be added to |dictionary|.
base::Value::Dict dictionary;
// Gather all log items which will be run in child processes.
const std::vector<Log> log_list = GetRequestedLogItems(requested_logs);
ParallelLogCollector log_helper(kFeedbackLogTimeout);
// Start a child process for each log item and collect logs async.
log_helper.StartGetLogs(log_list);
// Maps each subtask to a callable, which performs that task when invoked.
// Should not contain ordered tasks, as the invocation order is not preserved.
FuncMap subtasks;
// Get other logs in the current process while the log_helper is running log
// commands in other processes. They do not have the same interface as a Log.
// Except for the ArcBug report, they usually finish quickly.
LogMap temp_log_map;
std::array log_sources = {
LogSource{FeedbackLogType::ARC_BUG_REPORT, "GetArcBugReport",
base::BindOnce(&LogTool::GetArcBugReportInDictionary,
base::Unretained(this), username, &dictionary)},
LogSource{FeedbackLogType::BLUETOOTH_BQR, "GetBluetoothBqr",
base::BindOnce(&GetBluetoothBqr)},
LogSource{FeedbackLogType::LSB_RELEASE_INFO, "GetLsbReleaseInfo",
base::BindOnce(&GetLsbReleaseInfo, &temp_log_map)},
LogSource{FeedbackLogType::PERF_DATA, "GetPerfData",
base::BindOnce(&GetPerfData, &temp_log_map, perf_tool)},
LogSource{FeedbackLogType::OS_RELEASE_INFO, "GetOsReleaseInfo",
base::BindOnce(&GetOsReleaseInfo, &temp_log_map)}};
for (auto& [log_type, func_name, func_callback] : log_sources) {
if (requested_logs.empty() || base::Contains(requested_logs, log_type)) {
std::move(func_callback).Run();
sw.Lap(func_name);
}
}
// Merge temp_log_map into |dictionary|.
for (auto& map : temp_log_map) {
dictionary.Set(map.first, map.second);
}
// Wait for all child processes to complete and load the log data.
log_helper.EndGetLogs(&dictionary);
// The /usr/bin/chromeos-pgmem command gave the following error when run in
// log_helper: WARNING chromeos-pgmem: [process_meter.cc(255)] Unknown chrome
// process t.
// As a workaround, run it in current process.
// TODO(http://b/278123784): Investigate why the error occurred.
dictionary.Set(kPgmem.GetName(), kPgmem.GetLogData());
// Special handling for connectivity report. See the call to
// CreateConnectivityReport above for more details.
if (include_connectivity_report) {
const base::TimeDelta remaining_wait_time =
base::Seconds(kConnectionTesterTimeoutSeconds) -
(base::TimeTicks::Now() - connectivity_report_start_at);
if (remaining_wait_time.is_positive()) {
// Make sure we have waited at least kConnectionTesterTimeoutSeconds
// before collecting netlog.
usleep(remaining_wait_time.InMicroseconds());
}
// Collecting netlog is very quick. Doing it again is ok.
dictionary.Set(kNetLog.GetName(), kNetLog.GetLogData());
}
SerializeLogsAsJSON(dictionary, fd);
}
std::string GetSanitizedUsername(
org::chromium::CryptohomeMiscInterfaceProxyInterface* cryptohome_proxy,
const std::string& username) {
if (username.empty()) {
return std::string();
}
user_data_auth::GetSanitizedUsernameRequest request;
user_data_auth::GetSanitizedUsernameReply reply;
request.set_username(username);
brillo::ErrorPtr error;
if (!cryptohome_proxy->GetSanitizedUsername(request, &reply, &error)) {
LOG(ERROR) << "Failed to call GetSanitizedUsername, error: "
<< error->GetMessage();
return std::string();
}
return reply.sanitized_username();
}
std::string LogTool::GetArcBugReport(const std::string& username,
bool* is_backup) {
if (is_backup) {
*is_backup = true;
}
std::string userhash =
GetSanitizedUsername(cryptohome_proxy_.get(), username);
std::string contents;
std::string log_name;
if (userhash.empty() ||
arc_bug_report_backups_.find(userhash) == arc_bug_report_backups_.end() ||
!base::ReadFileToString(daemon_store_base_dir_.Append(userhash).Append(
kArcBugReportBackupFileName),
&contents)) {
// If |userhash| was not empty, but was not found in the backup set
// or the file did not exist, attempt to delete the file.
if (!userhash.empty()) {
DeleteArcBugReportBackup(username);
}
if (is_backup) {
*is_backup = false;
}
contents = arc_bug_report_log_->GetLogData();
}
return contents;
}
void LogTool::GetArcBugReportInDictionary(const std::string& username,
base::Value::Dict* dictionary) {
bool is_backup;
std::string arc_bug_report = GetArcBugReport(username, &is_backup);
dictionary->Set(kArcBugReportBackupKey, (is_backup ? "true" : "false"));
dictionary->Set(arc_bug_report_log_->GetName(), arc_bug_report);
}
void LogTool::BackupArcBugReport(const std::string& username) {
DLOG(INFO) << "Backing up ARC bug report";
const std::string userhash =
GetSanitizedUsername(cryptohome_proxy_.get(), username);
if (!IsUserHashValid(userhash)) {
LOG(ERROR) << "Invalid userhash '" << userhash << "'";
return;
}
brillo::SafeFD backupDir(
brillo::SafeFD::Root()
.first.OpenExistingDir(daemon_store_base_dir_.Append(userhash))
.first);
if (!backupDir.is_valid()) {
LOG(ERROR) << "Failed to open ARC bug report backup dir at "
<< daemon_store_base_dir_.Append(userhash).value();
return;
}
brillo::SafeFD backupFile(
brillo::OpenOrRemakeFile(&backupDir, kArcBugReportBackupFileName).first);
if (!backupFile.is_valid()) {
LOG(ERROR) << "Failed to open ARC bug report file at "
<< daemon_store_base_dir_.Append(userhash)
.Append(kArcBugReportBackupFileName)
.value();
return;
}
const std::string logData = arc_bug_report_log_->GetLogData();
if (backupFile.Write(logData.c_str(), logData.length()) ==
brillo::SafeFD::Error::kNoError) {
arc_bug_report_backups_.insert(userhash);
} else {
PLOG(ERROR) << "Failed to back up ARC bug report";
}
}
void LogTool::DeleteArcBugReportBackup(const std::string& username) {
DLOG(INFO) << "Deleting the ARC bug report backup";
const std::string userhash =
GetSanitizedUsername(cryptohome_proxy_.get(), username);
if (!IsUserHashValid(userhash)) {
LOG(ERROR) << "Invalid userhash '" << userhash << "'";
return;
}
brillo::SafeFD backupDir(
brillo::SafeFD::Root()
.first.OpenExistingDir(daemon_store_base_dir_.Append(userhash))
.first);
if (!backupDir.is_valid()) {
LOG(ERROR) << "Failed to open ARC bug report backup dir at "
<< daemon_store_base_dir_.Append(userhash).value();
return;
}
arc_bug_report_backups_.erase(userhash);
if (base::PathExists(daemon_store_base_dir_.Append(userhash).Append(
kArcBugReportBackupFileName)) &&
backupDir.Unlink(kArcBugReportBackupFileName) !=
brillo::SafeFD::Error::kNoError) {
PLOG(ERROR) << "Failed to delete ARC bug report backup at "
<< daemon_store_base_dir_.Append(userhash)
.Append(kArcBugReportBackupFileName)
.value();
}
}
// static
string LogTool::EncodeString(string value, LogTool::Encoding source_encoding) {
if (source_encoding == LogTool::Encoding::kBinary)
return value;
if (source_encoding == LogTool::Encoding::kAutodetect) {
if (base::IsStringUTF8(value))
return value;
source_encoding = LogTool::Encoding::kBase64;
}
if (source_encoding == LogTool::Encoding::kUtf8) {
string output;
const char* src = value.data();
size_t src_len = value.length();
output.reserve(value.size());
for (size_t char_index = 0; char_index < src_len; char_index++) {
base_icu::UChar32 code_point;
if (!base::ReadUnicodeCharacter(src, src_len, &char_index, &code_point) ||
!base::IsValidCharacter(code_point)) {
// Replace invalid characters with U+FFFD REPLACEMENT CHARACTER.
code_point = 0xFFFD;
}
base::WriteUnicodeCharacter(code_point, &output);
}
return output;
}
return "<base64>: " + base::Base64Encode(value);
}
} // namespace debugd