blob: b98c18383581451fa46963c0f554f53ea46cfb8a [file] [log] [blame]
// Copyright 2017 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 "diagnostics.h"
#include <functional>
#include <string>
#include <base/bind.h>
#include <base/callback.h>
#include <base/logging.h>
#include <base/macros.h>
#include <base/stl_util.h>
#include <base/strings/string_number_conversions.h>
#include <base/strings/stringprintf.h>
#include "util.h"
namespace atrusctl {
namespace {
using QueryResult = HIDRawDevice::QueryResult;
const uint16_t kCommandDaisySlaves = 0x1351;
const uint16_t kCommandHookStatus = 0x1601;
const uint16_t kCommandStateUptime = 0x1604;
const Diagnostics::DiagCommand kCommands[] = {
{0x1300, kCommandTypeExtended, "VERSION_MASTER"}, // VERSION_MASTER
{0x1310, kCommandTypeExtended, "VERSION_SLAVE1_UP"}, // VERSION_SLAVE1_UP
{0x1311, kCommandTypeExtended, "VERSION_SLAVE2_UP"}, // VERSION_SLAVE2_UP
{0x1312, kCommandTypeExtended, "VERSION_SLAVE3_UP"}, // VERSION_SLAVE3_UP
{0x1313, kCommandTypeExtended, "VERSION_SLAVE4_UP"}, // VERSION_SLAVE4_UP
{0x1314, kCommandTypeExtended,
"VERSION_SLAVE1_DOWN"}, // VERSION_SLAVE1_DOWN
{0x1315, kCommandTypeExtended,
"VERSION_SLAVE2_DOWN"}, // VERSION_SLAVE2_DOWN
{0x1316, kCommandTypeExtended,
"VERSION_SLAVE3_DOWN"}, // VERSION_SLAVE3_DOWN
{0x1317, kCommandTypeExtended,
"VERSION_SLAVE4_DOWN"}, // VERSION_SLAVE4_DOWN
{0x1350, kCommandTypeExtended, "DAISY_MIN_VERSION"}, // DAISY_MIN_VERSION
{kCommandDaisySlaves, kCommandTypePoll,
"Number of connected slaves"}, // DAISY_NUM_SLAVES
{0x1352, kCommandTypePoll, "Daisy power"}, // DAISY_POWER
{0x1500, kCommandTypePoll, "DFU status"},
{0x1600, kCommandTypePoll, "Mute status"},
{kCommandHookStatus, kCommandTypePoll, "Hook status"},
{0x1602, kCommandTypePoll, "Volume"}, // STATE_VOLUME
{0x1603, kCommandTypePoll, "LED status"}, // STATE_LED
{kCommandStateUptime, kCommandTypeExtended,
"Device uptime seconds"}, // STATE_UPTIME
{0x1605, kCommandTypePoll, "SHARC status"}, // STATE_SHARC_ALIVE
{0x1700, kCommandTypeExtended, "HW_ID"},
{0x1702, kCommandTypeExtended, "MIC_CALIBRATION"}, // MIC_CALIBRATION
{0x1703, kCommandTypeExtended, "Active boot partition"}, // BOOT_PARTITION
{0x1704, kCommandTypeExtended, "FGPA firmware version"}, // FGPA_FIRMWARE
{0x1706, kCommandTypePoll, "Mic selected"},
{0x1707, kCommandTypePoll, "Speaker selected"},
{0x1708, kCommandTypePoll, "Speaker audio"},
{0x1709, kCommandTypePoll,
"Number of detected ASRC mem errors"}, // ASRC_FIFO_MEM_ERRORS
{0x170A, kCommandTypePoll,
"Maximum ASRC mem error size"}, // ASRC_FIFO_ERROR_SIZE
{0x5001, kCommandTypePoll, "SPI queue status"}, // SPI_QUEUE_STATUS
{0x5002, kCommandTypePoll,
"Touchpad status"}, // TOUCH_ANALOG_CALIBRATION_STATUS
{0x5004, kCommandTypePoll, "Button presses"}, // NR_BUTTON_PRESSES
// Truevoice commands
{0x1800, kCommandTypeTruevoice, ""}, // TV_MIC_SELECTION
{0x1801, kCommandTypeTruevoice, ""}, // TV_ERLE_MIN
{0x1804, kCommandTypeTruevoice, ""}, // TV_ERLE_MAX
{0x1805, kCommandTypeTruevoice, ""}, // TV_ERLE_MEAN
{0x1807, kCommandTypeTruevoice, ""}, // TV_FEEDBACK_EST_MIN
{0x1808, kCommandTypeTruevoice, ""}, // TV_FEEDBACK_EST_MAX
{0x1809, kCommandTypeTruevoice, ""}, // TV_FEEDBACK_EST_MEAN
{0x180B, kCommandTypeTruevoice, ""}, // TV_NR_MIN
{0x180C, kCommandTypeTruevoice, ""}, // TV_NR_MAX
{0x180D, kCommandTypeTruevoice, ""}, // TV_NR_MEAN
{0x180F, kCommandTypeTruevoice, ""}, // TV_MIC_AVE_MIN
{0x1810, kCommandTypeTruevoice, ""}, // TV_MIC_AVE_MAX
{0x1811, kCommandTypeTruevoice, ""}, // TV_MIC_AVE_MEAN
{0x1813, kCommandTypeTruevoice, ""}, // TV_LS_NOISE_MIN
{0x1814, kCommandTypeTruevoice, ""}, // TV_LS_NOISE_MAX
{0x1815, kCommandTypeTruevoice, ""}, // TV_LS_NOISE_MEAN
{0x1817, kCommandTypeTruevoice, ""}, // TV_MIC_NOISE_MIN
{0x1818, kCommandTypeTruevoice, ""}, // TV_MIC_NOISE_MAX
{0x1819, kCommandTypeTruevoice, ""}, // TV_MIC_NOISE_MEAN
{0x181B, kCommandTypeTruevoice, ""}, // TV_GAMMA_MIN
{0x181C, kCommandTypeTruevoice, ""}, // TV_GAMMA_MAX
{0x181D, kCommandTypeTruevoice, ""}, // TV_GAMMA_MEAN
{0x181F, kCommandTypeTruevoice, ""}, // TV_LS_MIN
{0x1820, kCommandTypeTruevoice, ""}, // TV_LS_MAX
{0x1821, kCommandTypeTruevoice, ""}, // TV_LS_MEAN
{0x1823, kCommandTypeTruevoice, ""}, // TV_TX_MIN
{0x1824, kCommandTypeTruevoice, ""}, // TV_TX_MAX
{0x1825, kCommandTypeTruevoice, ""}, // TV_TX_MEAN
{0x1827, kCommandTypeTruevoice, ""}, // TV_TX_AGC_MIN
{0x1828, kCommandTypeTruevoice, ""}, // TV_TX_AGC_MAX
{0x1829, kCommandTypeTruevoice, ""}, // TV_TX_AGC_MEAN
{0x182B, kCommandTypeTruevoice, ""}, // TV_TX_LIMITER_MIN
{0x182C, kCommandTypeTruevoice, ""}, // TV_TX_LIMITER_MAX
{0x182D, kCommandTypeTruevoice, ""}, // TV_TX_LIMITER_MEAN
};
// TODO(karl@limesaudio.com): Remove this when fixed in firmware
const int64_t kDiagDelay = 10;
const int kPollIntervalSeconds = 5;
// Expected response when querying an Atrus device with the command
// |kCommandHookStatus| is either "Offhook" or "Onhook". We check for this
// string and assume the status is "Onhook" if the condition is false.
const char kCallOffHook[] = "Offhook";
// Because this is used to parse a string containing a number and trailing
// characters, check |new_value| rather than the return value of
// base::StringToInt to determine if a value was read.
bool ParseIntFromResponseBody(const std::string& str, int* val) {
int new_value = -1;
base::StringToInt(str, &new_value);
if (new_value == -1) {
LOG(ERROR) << "Failed to parse int from response: " << str;
return false;
}
*val = new_value;
return true;
}
// Helper function for extracting commands of a specific type from
// |kCommands|.
std::vector<Diagnostics::DiagCommand> GetDiagCommandsSubset(
std::function<bool(const Diagnostics::DiagCommand&)> cmpFn) {
std::vector<Diagnostics::DiagCommand> vec;
std::copy_if(std::begin(kCommands), std::end(kCommands),
std::back_inserter(vec), cmpFn);
return vec;
}
} // namespace
Diagnostics::Diagnostics()
: commands_poll_(GetDiagCommandsSubset([](const DiagCommand& cmd) {
return (cmd.type == kCommandTypePoll);
})),
commands_extended_(GetDiagCommandsSubset([](const DiagCommand& cmd) {
return (cmd.type == kCommandTypeExtended) ||
(cmd.type == kCommandTypePoll);
})),
commands_truevoice_(GetDiagCommandsSubset([](const DiagCommand& cmd) {
return (cmd.type == kCommandTypeTruevoice);
})) {
ResetSessionState();
}
Diagnostics::~Diagnostics() {
Stop();
}
void Diagnostics::Start(const base::TimeDelta& diag_interval,
const base::TimeDelta& ext_diag_interval,
const std::string& device_path) {
if (diag_timer_.IsRunning()) {
LOG(INFO) << "Diagnostics started while already running";
diag_timer_.Stop();
poll_timer_.Stop();
}
ResetSessionState();
ext_diag_interval_ = ext_diag_interval;
// Perform an extended diagnostic the first time
last_extended_diag_time_ = base::TimeTicks();
device_.set_path(device_path);
poll_timer_.Start(
FROM_HERE, base::TimeDelta::FromSeconds(kPollIntervalSeconds),
base::Bind(&Diagnostics::Poll, base::Unretained(this), commands_poll_));
// Run a diagnostic immediately, then do it periodically
Run();
diag_timer_.Start(FROM_HERE, diag_interval,
base::Bind(&Diagnostics::Run, base::Unretained(this)));
// TODO(karlpeterson@google.com): fetch all truevoice parameters on start
// to reset internal state
}
void Diagnostics::Stop() {
if (diag_timer_.IsRunning()) {
diag_timer_.Stop();
}
if (poll_timer_.IsRunning()) {
poll_timer_.Stop();
}
}
void Diagnostics::Run() {
const base::TimeTicks now = base::TimeTicks::Now();
// If a call is active, log TrueVoice parameters
if (diagnostic_values_[kCommandHookStatus].find(kCallOffHook) !=
std::string::npos) {
VLOG(1) << "Internal TrueVoice parameters: ";
QueryDeviceWithCommands(commands_truevoice_);
}
if (now - last_extended_diag_time_ > ext_diag_interval_) {
should_do_extended_diagnose_ = true;
}
if (should_do_extended_diagnose_) {
should_do_extended_diagnose_ = false;
last_extended_diag_time_ = now;
LOG(INFO) << "-- Extended report --";
QueryDeviceWithCommands(commands_extended_);
LOG(INFO) << "Number of USB devices connected: "
<< number_of_connected_devices_;
}
}
void Diagnostics::QueryDeviceWithCommands(
const std::vector<DiagCommand>& commands) {
for (const DiagCommand& command : commands) {
device_.Query(command.id, base::Bind(&Diagnostics::HandleQueryResult,
base::Unretained(this), command));
// Workaround for firmware < v0.7.0
// TODO(karl@limesaudio.com): Remove this when fixed in firmware
// TODO(karl@limesaudio.com) Update: Due to issues with USB performance
// for fast volume events, keep this until we can verify that it does not
// stress the Atrus further
TimeoutMs(kDiagDelay);
}
}
void Diagnostics::Poll(const std::vector<DiagCommand>& commands) {
for (const DiagCommand& command : commands) {
device_.Query(command.id, base::Bind(&Diagnostics::HandlePollQueryResult,
base::Unretained(this), command));
// Workaround for firmware < v0.7.0
// TODO(karl@limesaudio.com): Remove this when fixed in firmware
// TODO(karl@limesaudio.com) Update: Due to issues with USB performance
// for fast volume events, keep this until we can verify that it does not
// stress the Atrus further
TimeoutMs(kDiagDelay);
}
}
void Diagnostics::LogResponse(const std::string& cmd_desc,
const HIDMessage& response) {
if (VLOG_IS_ON(1)) {
LOG(INFO) << cmd_desc << " " << response.ToString();
} else {
LOG(INFO) << response.ToString();
}
}
void Diagnostics::LogQueryError(QueryResult code, const HIDMessage& request) {
switch (code) {
case QueryResult::kQueryUnknownResponse:
LOG(INFO) << base::StringPrintf("0x%04X: Error: unknown response",
request.command_id());
break;
case QueryResult::kQueryError:
LOG(INFO) << base::StringPrintf("0x%04X: Error: report failed",
request.command_id());
break;
case QueryResult::kQueryNotValid:
LOG(INFO) << base::StringPrintf(
"0x%04X: Error: Command not supported by device.",
request.command_id());
break;
case QueryResult::kQueryTimeout:
LOG(INFO) << base::StringPrintf("0x%04X: Error: timeout",
request.command_id());
break;
case QueryResult::kQuerySuccess:
default:
LOG(INFO) << base::StringPrintf("0x%04X: Unhandled error",
request.command_id());
break;
}
}
bool Diagnostics::StoreDiagnosticResult(const DiagCommand& command,
const HIDMessage& response) {
bool value_changed = false;
uint16_t response_id = response.command_id();
if (diagnostic_values_.count(response_id) <= 0) {
LOG(INFO) << base::StringPrintf(
"0x%04X is not expected to have it's value cached (is it a non-poll "
"command?)",
response_id);
return false;
}
const std::string& response_body = response.body();
if (diagnostic_values_[response_id] != response_body) {
diagnostic_values_[response_id] = response_body;
value_changed = true;
}
int new_value;
switch (response_id) {
case kCommandStateUptime:
if (ParseIntFromResponseBody(response_body, &new_value)) {
UpdateUptime(new_value);
}
break;
case kCommandDaisySlaves:
if (ParseIntFromResponseBody(response_body, &new_value)) {
UpdateNumberOfConnectedSlaves(new_value);
}
break;
}
return value_changed;
}
void Diagnostics::HandleQueryResult(const DiagCommand& command,
QueryResult code,
const HIDMessage& request,
const HIDMessage& response) {
if (code != QueryResult::kQuerySuccess) {
return LogQueryError(code, request);
}
if (command.type == kCommandTypePoll) {
StoreDiagnosticResult(command, response);
}
LogResponse(command.description, response);
}
void Diagnostics::HandlePollQueryResult(const DiagCommand& command,
QueryResult code,
const HIDMessage& request,
const HIDMessage& response) {
// Only log these if their values changed since the last poll.
if (code != QueryResult::kQuerySuccess) {
return; // don't log errors when we poll, that would bloat the log
}
if (StoreDiagnosticResult(command, response)) {
LogResponse(command.description, response);
}
}
void Diagnostics::UpdateNumberOfDevices(int new_value) {
if (new_value != number_of_connected_devices_) {
should_do_extended_diagnose_ = true;
}
number_of_connected_devices_ = new_value;
}
void Diagnostics::UpdateUptime(int new_value) {
if (new_value < uptime_) {
should_do_extended_diagnose_ = true;
}
uptime_ = new_value;
}
bool Diagnostics::UpdateNumberOfConnectedSlaves(int new_value) {
if (new_value != number_of_connected_slaves_) {
should_do_extended_diagnose_ = true;
number_of_connected_slaves_ = new_value;
return true;
}
return false;
}
void Diagnostics::ResetSessionState() {
uptime_ = 0;
number_of_connected_slaves_ = 0;
// don't reset |number_of_connected_devices_|, it's updated on udev events
for (const DiagCommand& cmd : commands_poll_) {
diagnostic_values_[cmd.id] = "";
}
}
} // namespace atrusctl