| // Copyright 2015 The Chromium OS Authors. All rights reserved. |
| // Use of this source code is governed by a BSD-style license that can be |
| // found in the LICENSE file. |
| |
| #include <algorithm> |
| #include <sstream> |
| #include <string> |
| |
| #include <sysexits.h> |
| #include <sys/types.h> |
| |
| #include <base/bind.h> |
| #include <base/bind_helpers.h> |
| #include <base/files/file_util.h> |
| #include <base/files/file_path.h> |
| #include <base/logging.h> |
| #include <base/message_loop/message_loop.h> |
| #include <base/strings/stringprintf.h> |
| #include <base/strings/string_number_conversions.h> |
| #include <base/time/time.h> |
| #include <brillo/daemons/daemon.h> |
| #include "timberslide/log_listener_factory.h" |
| #include "timberslide/timberslide.h" |
| |
| namespace timberslide { |
| namespace { |
| |
| const char kCurrentLogExt[] = ".log"; |
| const char kPreviousLogExt[] = ".previous"; |
| const int kMaxCurrentLogSize = 10 * 1024 * 1024; |
| |
| // String proxy class for dealing with lines. |
| class LineExtractor { |
| public: |
| // Extract one line from beginning of string stream. |
| friend std::istream& operator>>(std::istream& is, LineExtractor& l) { |
| std::getline(is, l.str_); |
| return is; |
| } |
| |
| // Transparently convert to std::string. |
| operator std::string() const { return str_; } |
| |
| private: |
| std::string str_; |
| }; |
| |
| // |
| // Has a member function which adds the host timestamp |
| // to the beginning of each line passed to it. |
| // |
| class StringTransformer { |
| public: |
| explicit StringTransformer(int64_t ec_uptime_ms, const base::Time& now) |
| : ec_current_uptime_ms_(ec_uptime_ms), timestamp_(now) {} |
| |
| // Matching lines look like: [1234.5678 EC message goes here] . |
| std::string add_host_ts(const std::string& s) { |
| const base::TimeDelta ec_sync( |
| base::TimeDelta::FromMilliseconds(ec_current_uptime_ms_)); |
| |
| std::string::size_type bracket = s.find('['); |
| if (bracket == std::string::npos) |
| return s; |
| |
| std::string::size_type space = s.find(' ', bracket + 1); |
| if (space == std::string::npos) |
| return s; |
| |
| double ec_ts; |
| const std::string potential_ts(s.substr(bracket + 1, space - bracket - 1)); |
| |
| if (!base::StringToDouble(potential_ts, &ec_ts)) { |
| LOG(WARNING) << "Unable to convert " << potential_ts << " to a double"; |
| return s; |
| } |
| |
| // Calculate delta from EC's uptime. |
| const base::TimeDelta logline_tm(base::TimeDelta::FromSecondsD(ec_ts)); |
| const base::TimeDelta logline_delta(ec_sync - logline_tm); |
| const base::Time logline_host_tm = timestamp_ - logline_delta; |
| |
| return FormatTime(logline_host_tm).append(" ").append(s); |
| } |
| |
| private: |
| std::string FormatTime(const base::Time& time) { |
| base::Time::Exploded e; |
| |
| // This format matches the format in libchrome/base/logging.cc |
| time.UTCExplode(&e); |
| return base::StringPrintf("%02d%02d/%02d%02d%02d.%06d", e.month, |
| e.day_of_month, e.hour, e.minute, e.second, |
| e.millisecond * 1000); |
| } |
| |
| int64_t ec_current_uptime_ms_; |
| base::Time timestamp_; |
| }; |
| |
| } // namespace |
| |
| TimberSlide::TimberSlide(const std::string& ec_type, |
| base::File device_file, |
| base::File uptime_file, |
| const base::FilePath& log_dir) |
| : device_file_(std::move(device_file)), |
| total_size_(0), |
| uptime_file_(std::move(uptime_file)), |
| uptime_file_valid_(uptime_file_.IsValid()) { |
| current_log_ = log_dir.Append(ec_type + kCurrentLogExt); |
| previous_log_ = log_dir.Append(ec_type + kPreviousLogExt); |
| log_listener_ = LogListenerFactory::Create(ec_type); |
| } |
| |
| TimberSlide::TimberSlide(std::unique_ptr<LogListener> log_listener) |
| : log_listener_(std::move(log_listener)) {} |
| |
| int TimberSlide::OnInit() { |
| LOG(INFO) << "Starting timberslide daemon"; |
| int ret = brillo::Daemon::OnInit(); |
| if (ret != EX_OK) |
| return ret; |
| |
| if (uptime_file_valid_) |
| LOG(INFO) << "EC uptime file is valid"; |
| else |
| LOG(WARNING) << "EC uptime file is not valid; ignoring"; |
| |
| RotateLogs(previous_log_, current_log_); |
| |
| watcher_ = base::FileDescriptorWatcher::WatchReadable( |
| device_file_.GetPlatformFile(), |
| base::BindRepeating(&TimberSlide::OnEventReadable, |
| base::Unretained(this))); |
| |
| return watcher_ ? EX_OK : EX_OSERR; |
| } |
| |
| // |
| // From kernel's Documentation/filesystems/sysfs.txt: If userspace seeks back |
| // to zero or does a pread(2) with an offset of '0' the show() method will |
| // be called again, rearmed, to fill the buffer. |
| // |
| // Therefore, the 'uptime' file will be kept open and just seeked back to |
| // 0 when new uptime is needed. |
| // |
| bool TimberSlide::GetEcUptime(int64_t* ec_uptime_ms) { |
| char uptime_buf[64] = {0}; |
| |
| if (!uptime_file_valid_ || uptime_file_.Seek(base::File::FROM_BEGIN, 0) != 0) |
| return false; |
| |
| // Read single line from file and parse as a number. |
| int count = uptime_file_.ReadAtCurrentPos(uptime_buf, sizeof(uptime_buf) - 1); |
| |
| if (count <= 0) |
| return false; |
| |
| uptime_buf[count] = '\0'; |
| base::StringToInt64(uptime_buf, ec_uptime_ms); |
| |
| // If the 'uptime' file contains zero, that means the kernel patch is |
| // available, but the EC doesn't support EC_CMD_GET_UPTIME_INFO. In |
| // that case, this returns false so that incorrect times aren't reported |
| // in the EC log file. |
| return (*ec_uptime_ms > 0); |
| } |
| |
| std::string TimberSlide::ProcessLogBuffer(const char* buffer, |
| const base::Time& now) { |
| int64_t ec_current_uptime_ms = 0; |
| std::istringstream iss(buffer); |
| |
| bool have_ec_uptime = GetEcUptime(&ec_current_uptime_ms); |
| |
| auto fn_xfrm = [this, ec_current_uptime_ms, have_ec_uptime, |
| now](const std::string& line) { |
| if (log_listener_) { |
| log_listener_->OnLogLine(line); |
| } |
| if (!have_ec_uptime) { |
| return line; |
| } |
| StringTransformer xfrm(ec_current_uptime_ms, now); |
| return xfrm.add_host_ts(line); |
| }; |
| |
| // Iterate over each line and prepend the corresponding host timestamp if we |
| // have it |
| std::ostringstream oss; |
| std::transform(std::istream_iterator<LineExtractor>(iss), |
| std::istream_iterator<LineExtractor>(), |
| std::ostream_iterator<std::string>(oss, "\n"), fn_xfrm); |
| |
| return oss.str(); |
| } |
| |
| |
| void TimberSlide::OnEventReadable() { |
| char buffer[4096]; |
| int ret; |
| |
| memset(buffer, 0, sizeof(buffer)); |
| |
| ret = TEMP_FAILURE_RETRY( |
| device_file_.ReadAtCurrentPosNoBestEffort(buffer, sizeof(buffer))); |
| if (ret == 0) |
| return; |
| |
| if (ret < 0) { |
| PLOG(ERROR) << "Read error"; |
| Quit(); |
| return; |
| } |
| |
| std::string str = ProcessLogBuffer(buffer, base::Time::Now()); |
| ret = str.size(); |
| |
| if (!base::AppendToFile(current_log_, str.c_str(), ret)) { |
| PLOG(ERROR) << "Could not append to log file"; |
| Quit(); |
| return; |
| } |
| |
| total_size_ += ret; |
| if (total_size_ >= kMaxCurrentLogSize) { |
| RotateLogs(previous_log_, current_log_); |
| total_size_ = 0; |
| } |
| } |
| |
| void TimberSlide::RotateLogs(const base::FilePath& previous_log, |
| const base::FilePath& current_log) { |
| CHECK(base::DeleteFile(previous_log, /* recursive = */ false)); |
| |
| if (base::PathExists(current_log)) |
| CHECK(base::Move(current_log, previous_log)); |
| |
| base::WriteFile(current_log, "", 0); |
| } |
| |
| } // namespace timberslide |