[audio][hda] Update Intel HDA driver logging.
Update the Intel HDA driver's logging to use zxlogf instead of printf.
Change-Id: Ice8ef22e7ae48da566b16fbb705a6a3d148f2d6c
diff --git a/system/dev/audio/intel-hda/controller/debug-logging.h b/system/dev/audio/intel-hda/controller/debug-logging.h
index ac9575b..d66aed6 100644
--- a/system/dev/audio/intel-hda/controller/debug-logging.h
+++ b/system/dev/audio/intel-hda/controller/debug-logging.h
@@ -4,55 +4,17 @@
#pragma once
+#include <ddk/debug.h>
#include <inttypes.h>
-#include <stdio.h>
-// TODO(johngro) : replace this with a system which...
+// Notes: The TRACE and SPEW levels of logging are disabled by default. In
+// order to enable them, you can pass something like the following in the kernel
+// command line args.
//
-// 1) Uses low overhead loging service infrastructure instead of printf.
-// 2) Uses C/C++ functions (either template parameter packs, or c-style
-// var-args) instead of preprocessor macros.
+// driver.intel_hda.log=+trace,+spew
+//
+constexpr size_t LOG_PREFIX_STORAGE = 32;
-#define VERBOSE_LOGGING 0
-#define DEBUG_LOGGING (VERBOSE_LOGGING || 0)
-
-#define GLOBAL_LOG(...) do { \
- printf("[IHDA Driver] " __VA_ARGS__); \
-} while (false)
-
-#define GLOBAL_DEBUG_LOG(...) do { \
- if (DEBUG_LOGGING) { \
- printf("[IHDA Driver] " __VA_ARGS__); \
- } \
-} while (false)
-
-#define GLOBAL_VERBOSE_LOG(...) do { \
- if (VERBOSE_LOGGING) { \
- printf("[IHDA Driver] " __VA_ARGS__); \
- } \
-} while (false)
-
-#define LOG_EX(obj, ...) do { \
- (obj).PrintDebugPrefix(); \
- printf(__VA_ARGS__); \
-} while (false)
-
-#define LOG(...) LOG_EX(*this, __VA_ARGS__)
-
-#define DEBUG_LOG_EX(obj, ...) do { \
- if (DEBUG_LOGGING) { \
- (obj).PrintDebugPrefix(); \
- printf(__VA_ARGS__); \
- } \
-} while (false)
-
-#define DEBUG_LOG(...) DEBUG_LOG_EX(*this, __VA_ARGS__)
-
-#define VERBOSE_LOG_EX(obj, ...) do { \
- if (VERBOSE_LOGGING) { \
- (obj).PrintDebugPrefix(); \
- printf(__VA_ARGS__); \
- } \
-} while (false)
-
-#define VERBOSE_LOG(...) VERBOSE_LOG_EX(*this, __VA_ARGS__)
+#define GLOBAL_LOG(level, ...) zxlogf(level, "[IHDA Driver] " __VA_ARGS__)
+#define LOG_EX(level, obj, fmt, ...) zxlogf(level, "[%s] " fmt, (obj).log_prefix(), ## __VA_ARGS__)
+#define LOG(level, fmt, ...) LOG_EX(level, *this, fmt, ## __VA_ARGS__)
diff --git a/system/dev/audio/intel-hda/controller/intel-hda-codec.cpp b/system/dev/audio/intel-hda/controller/intel-hda-codec.cpp
index 6412a8f..e7b27b0 100644
--- a/system/dev/audio/intel-hda/controller/intel-hda-codec.cpp
+++ b/system/dev/audio/intel-hda/controller/intel-hda-codec.cpp
@@ -39,10 +39,6 @@
{ .verb = GET_PARAM(CodecParam::REVISION_ID), .parse = &IntelHDACodec::ParseRevisionId },
};
-void IntelHDACodec::PrintDebugPrefix() const {
- printf("[%s:%u] ", controller_.dev_name(), codec_id_);
-}
-
#define DEV (static_cast<IntelHDACodec*>(ctx))
zx_protocol_device_t IntelHDACodec::CODEC_DEVICE_THUNKS = {
.version = DEVICE_OPS_VERSION,
@@ -85,6 +81,11 @@
dev_props_[PROP_PROTOCOL].id = BIND_PROTOCOL;
dev_props_[PROP_PROTOCOL].value = ZX_PROTOCOL_IHDA_CODEC;
default_domain_ = dispatcher::ExecutionDomain::Create();
+
+ const auto& info = controller_.dev_info();
+ snprintf(log_prefix_, sizeof(log_prefix_),
+ "IHDA Codec %02x:%02x.%01x/%02x",
+ info.bus_id, info.dev_id, info.func_id, codec_id_);
}
fbl::RefPtr<IntelHDACodec> IntelHDACodec::Create(IntelHDAController& controller,
@@ -94,12 +95,12 @@
fbl::AllocChecker ac;
auto ret = fbl::AdoptRef(new (&ac) IntelHDACodec(controller, codec_id));
if (!ac.check()) {
- GLOBAL_LOG("Out of memory attempting to allocate codec\n");
+ GLOBAL_LOG(ERROR, "Out of memory attempting to allocate codec\n");
return nullptr;
}
if (ret->default_domain_ == nullptr) {
- LOG_EX(*ret, "Out of memory attempting to allocate execution domain\n");
+ LOG_EX(ERROR, *ret, "Out of memory attempting to allocate execution domain\n");
return nullptr;
}
@@ -114,13 +115,13 @@
auto job = CodecCmdJobAllocator::New(cmd);
if (job == nullptr) {
- LOG("Failed to allocate job during initial codec probe!\n");
+ LOG(ERROR, "Failed to allocate job during initial codec probe!\n");
return ZX_ERR_NO_MEMORY;
}
zx_status_t res = controller_.QueueCodecCmd(fbl::move(job));
if (res != ZX_OK) {
- LOG("Failed to queue job (res = %d) during initial codec probe!\n", res);
+ LOG(ERROR, "Failed to queue job (res = %d) during initial codec probe!\n", res);
return res;
}
}
@@ -141,8 +142,8 @@
zx_status_t res = channel->Write(&payload, sizeof(payload));
if (res != ZX_OK) {
- DEBUG_LOG("Error writing CORB response (%08x, %08x) res = %d\n",
- resp.data, resp.data_ex, res);
+ LOG(TRACE, "Error writing CORB response (%08x, %08x) res = %d\n",
+ resp.data, resp.data_ex, res);
}
}
@@ -160,14 +161,15 @@
if (res == ZX_OK) {
++probe_rx_ndx_;
} else {
- LOG("Error parsing solicited response during codec probe! (data %08x)\n",
- resp.data);
+ LOG(ERROR,
+ "Error parsing solicited response during codec probe! (data %08x)\n",
+ resp.data);
// TODO(johngro) : shutdown and cleanup somehow.
state_ = State::FATAL_ERROR;
}
} else if (job->response_channel() != nullptr) {
- VERBOSE_LOG("Sending solicited response [%08x, %08x] to channel %p\n",
+ LOG(SPEW, "Sending solicited response [%08x, %08x] to channel %p\n",
resp.data, resp.data_ex, job->response_channel().get());
// Does this job have a response channel? If so, attempt to send the
@@ -199,7 +201,7 @@
//
// Currently, we support neither power management, nor hot-unplug. Just log
// the fact that we have been woken up and do nothing.
- LOG("Wakeup event received!\n");
+ LOG(WARN, "Wakeup event received - Don't know how to handle this yet!\n");
}
void IntelHDACodec::BeginShutdown() {
@@ -245,7 +247,7 @@
// Publish the device.
zx_status_t res = device_add(controller_.dev_node(), &args, &dev_node_);
if (res != ZX_OK) {
- LOG("Failed to add codec device for \"%s\" (res %d)\n", name, res);
+ LOG(ERROR, "Failed to add codec device for \"%s\" (res %d)\n", name, res);
return res;
}
@@ -296,20 +298,20 @@
#define PROCESS_CMD(_req_ack, _req_driver_chan, _ioctl, _payload, _handler) \
case _ioctl: \
if (req_size != sizeof(req._payload)) { \
- DEBUG_LOG("Bad " #_payload \
- " request length (%u != %zu)\n", \
- req_size, sizeof(req._payload)); \
+ LOG(TRACE, "Bad " #_payload \
+ " request length (%u != %zu)\n", \
+ req_size, sizeof(req._payload)); \
return ZX_ERR_INVALID_ARGS; \
} \
if (_req_ack && (req.hdr.cmd & IHDA_NOACK_FLAG)) { \
- DEBUG_LOG("Cmd " #_payload \
- " requires acknowledgement, but the " \
- "NOACK flag was set!\n"); \
+ LOG(TRACE, "Cmd " #_payload \
+ " requires acknowledgement, but the " \
+ "NOACK flag was set!\n"); \
return ZX_ERR_INVALID_ARGS; \
} \
if (_req_driver_chan && !is_driver_channel) { \
- DEBUG_LOG("Cmd " #_payload \
- " requires a privileged driver channel.\n"); \
+ LOG(TRACE, "Cmd " #_payload \
+ " requires a privileged driver channel.\n"); \
return ZX_ERR_ACCESS_DENIED; \
} \
return _handler(channel, req._payload)
@@ -332,25 +334,25 @@
ZX_DEBUG_ASSERT(channel != nullptr);
res = channel->Read(&req, sizeof(req), &req_size);
if (res != ZX_OK) {
- DEBUG_LOG("Failed to read client request (res %d)\n", res);
+ LOG(TRACE, "Failed to read client request (res %d)\n", res);
return res;
}
// Sanity checks.
if (req_size < sizeof(req.hdr)) {
- DEBUG_LOG("Client request too small to contain header (%u < %zu)\n",
+ LOG(TRACE,"Client request too small to contain header (%u < %zu)\n",
req_size, sizeof(req.hdr));
return ZX_ERR_INVALID_ARGS;
}
auto cmd_id = static_cast<ihda_cmd_t>(req.hdr.cmd & ~IHDA_NOACK_FLAG);
if (req.hdr.transaction_id == IHDA_INVALID_TRANSACTION_ID) {
- DEBUG_LOG("Invalid transaction ID in client request 0x%04x\n", cmd_id);
+ LOG(TRACE, "Invalid transaction ID in client request 0x%04x\n", cmd_id);
return ZX_ERR_INVALID_ARGS;
}
// Dispatch
- VERBOSE_LOG("Client Request (cmd 0x%04x tid %u) len %u\n",
+ LOG(SPEW, "Client Request (cmd 0x%04x tid %u) len %u\n",
req.hdr.cmd,
req.hdr.transaction_id,
req_size);
@@ -363,7 +365,7 @@
PROCESS_CMD(false, CodecVerb(req.corb_cmd.verb).is_set(),
IHDA_CODEC_SEND_CORB_CMD, corb_cmd, ProcessSendCORBCmd);
default:
- DEBUG_LOG("Unrecognized command ID 0x%04x\n", req.hdr.cmd);
+ LOG(TRACE, "Unrecognized command ID 0x%04x\n", req.hdr.cmd);
return ZX_ERR_INVALID_ARGS;
}
}
@@ -420,7 +422,7 @@
// Make sure that the command is well formed.
if (!CodecCommand::SanityCheck(id(), req.nid, verb)) {
- DEBUG_LOG("Bad SEND_CORB_CMD request values [%u, %hu, 0x%05x]\n",
+ LOG(TRACE, "Bad SEND_CORB_CMD request values [%u, %hu, 0x%05x]\n",
id(), req.nid, verb.val);
return ZX_ERR_INVALID_ARGS;
}
@@ -438,7 +440,7 @@
zx_status_t res = controller_.QueueCodecCmd(fbl::move(job));
if (res != ZX_OK) {
- DEBUG_LOG("Failed to queue CORB command [%u, %hu, 0x%05x] (res %d)\n",
+ LOG(TRACE, "Failed to queue CORB command [%u, %hu, 0x%05x] (res %d)\n",
id(), req.nid, verb.val, res);
}
@@ -512,7 +514,7 @@
// Sanity check the requested format.
if (!StreamFormat(req.format).SanityCheck()) {
- DEBUG_LOG("Invalid encoded stream format 0x%04hx!\n", req.format);
+ LOG(TRACE, "Invalid encoded stream format 0x%04hx!\n", req.format);
return ZX_ERR_INVALID_ARGS;
}
@@ -538,7 +540,7 @@
req.format,
&client_channel);
if (res != ZX_OK) {
- DEBUG_LOG("Failed to set stream format 0x%04hx for stream %hu (res %d)\n",
+ LOG(TRACE, "Failed to set stream format 0x%04hx for stream %hu (res %d)\n",
req.format, req.stream_id, res);
return res;
}
@@ -550,7 +552,7 @@
res = channel->Write(&resp, sizeof(resp), fbl::move(client_channel));
if (res != ZX_OK)
- DEBUG_LOG("Failed to send stream channel back to codec driver (res %d)\n", res);
+ LOG(TRACE, "Failed to send stream channel back to codec driver (res %d)\n", res);
return res;
}
diff --git a/system/dev/audio/intel-hda/controller/intel-hda-codec.h b/system/dev/audio/intel-hda/controller/intel-hda-codec.h
index caabc67..2e00273 100644
--- a/system/dev/audio/intel-hda/controller/intel-hda-codec.h
+++ b/system/dev/audio/intel-hda/controller/intel-hda-codec.h
@@ -22,6 +22,7 @@
#include <intel-hda/utils/intel-hda-registers.h>
#include "codec-cmd-job.h"
+#include "debug-logging.h"
#include "intel-hda-stream.h"
#include "thread-annotations.h"
@@ -44,7 +45,6 @@
static fbl::RefPtr<IntelHDACodec> Create(IntelHDAController& controller, uint8_t codec_id);
- void PrintDebugPrefix() const;
zx_status_t Startup();
void ProcessSolicitedResponse(const CodecResponse& resp, fbl::unique_ptr<CodecCmdJob>&& job);
void ProcessUnsolicitedResponse(const CodecResponse& resp);
@@ -59,6 +59,7 @@
uint8_t id() const { return codec_id_; }
State state() const { return state_; }
+ const char* log_prefix() const { return log_prefix_; }
// Debug/Diags
void DumpState();
@@ -138,6 +139,9 @@
uint8_t step_id;
} props_;
+ // Log prefix storage
+ char log_prefix_[LOG_PREFIX_STORAGE] = { 0 };
+
// Dispatcher framework state.
fbl::RefPtr<dispatcher::ExecutionDomain> default_domain_;
diff --git a/system/dev/audio/intel-hda/controller/intel-hda-controller-init.cpp b/system/dev/audio/intel-hda/controller/intel-hda-controller-init.cpp
index f927154..a4cd0cb 100644
--- a/system/dev/audio/intel-hda/controller/intel-hda-controller-init.cpp
+++ b/system/dev/audio/intel-hda/controller/intel-hda-controller-init.cpp
@@ -44,7 +44,8 @@
+ HDA_REG_GCAP_BSS(gcap);
if (total_stream_cnt > countof(regs()->stream_desc)) {
- LOG("Fatal error during reset! Controller reports more streams (%u) "
+ LOG(ERROR,
+ "Fatal error during reset! Controller reports more streams (%u) "
"than should be possible for IHDA hardware. (GCAP = 0x%04hx)\n",
total_stream_cnt, gcap);
return ZX_ERR_INTERNAL;
@@ -73,7 +74,7 @@
regs());
if (res != ZX_OK) {
- LOG("Error attempting to enter reset! (res %d)\n", res);
+ LOG(ERROR, "Error attempting to enter reset! (res %d)\n", res);
return res;
}
@@ -93,7 +94,7 @@
regs());
if (res != ZX_OK) {
- LOG("Error attempting to leave reset! (res %d)\n", res);
+ LOG(ERROR, "Error attempting to leave reset! (res %d)\n", res);
return res;
}
@@ -144,7 +145,7 @@
// Have we already been set up?
if (pci_dev_ != nullptr) {
- LOG("Device already initialized!\n");
+ LOG(ERROR, "Device already initialized!\n");
return ZX_ERR_BAD_STATE;
}
@@ -154,13 +155,10 @@
pci_dev_ = pci_dev;
- // Generate a default debug tag for now.
- snprintf(debug_tag_, sizeof(debug_tag_), "IHDA Controller (unknown BDF)");
-
// The device had better be a PCI device, or we are very confused.
res = device_get_protocol(pci_dev_, ZX_PROTOCOL_PCI, reinterpret_cast<void*>(&pci_));
if (res != ZX_OK) {
- LOG("PCI device does not support PCI protocol! (res %d)\n", res);
+ LOG(ERROR, "PCI device does not support PCI protocol! (res %d)\n", res);
return res;
}
@@ -169,11 +167,11 @@
ZX_DEBUG_ASSERT(pci_.ops != nullptr);
res = pci_get_device_info(&pci_, &pci_dev_info_);
if (res != ZX_OK) {
- LOG("Failed to fetch basic PCI device info! (res %d)\n", res);
+ LOG(ERROR, "Failed to fetch basic PCI device info! (res %d)\n", res);
return res;
}
- snprintf(debug_tag_, sizeof(debug_tag_), "IHDA Controller %02x:%02x.%01x",
+ snprintf(log_prefix_, sizeof(log_prefix_), "IHDA Controller %02x:%02x.%01x",
pci_dev_info_.bus_id,
pci_dev_info_.dev_id,
pci_dev_info_.func_id);
@@ -184,13 +182,13 @@
zx::bti pci_bti;
res = pci_get_bti(&pci_, 0, pci_bti.reset_and_get_address());
if (res != ZX_OK) {
- LOG("Failed to get BTI handle for IHDA Controller (res %d)\n", res);
+ LOG(ERROR, "Failed to get BTI handle for IHDA Controller (res %d)\n", res);
return res;
}
pci_bti_ = RefCountedBti::Create(fbl::move(pci_bti));
if (pci_bti_ == nullptr) {
- LOG("Out of memory while attempting to allocate BTI wrapper for IHDA Controller\n");
+ LOG(ERROR, "Out of memory while attempting to allocate BTI wrapper for IHDA Controller\n");
return ZX_ERR_NO_MEMORY;
}
@@ -199,19 +197,20 @@
zx_pci_bar_t bar_info;
res = pci_get_bar(&pci_, 0u, &bar_info);
if (res != ZX_OK) {
- LOG("Error attempting to fetch registers from PCI (res %d)\n", res);
+ LOG(ERROR, "Error attempting to fetch registers from PCI (res %d)\n", res);
return res;
}
if (bar_info.type != PCI_BAR_TYPE_MMIO) {
- LOG("Bad register window type (expected %u got %u)\n", PCI_BAR_TYPE_MMIO, bar_info.type);
+ LOG(ERROR, "Bad register window type (expected %u got %u)\n",
+ PCI_BAR_TYPE_MMIO, bar_info.type);
return ZX_ERR_INTERNAL;
}
// We should have a valid handle now, make sure we don't leak it.
zx::vmo bar_vmo(bar_info.handle);
if (bar_info.size != sizeof(hda_all_registers_t)) {
- LOG("Bad register window size (expected 0x%zx got 0x%zx)\n",
+ LOG(ERROR, "Bad register window size (expected 0x%zx got 0x%zx)\n",
sizeof(hda_all_registers_t), bar_info.size);
return ZX_ERR_INTERNAL;
}
@@ -220,7 +219,7 @@
// cache policy to UNCACHED_DEVICE
res = bar_vmo.set_cache_policy(ZX_CACHE_POLICY_UNCACHED_DEVICE);
if (res != ZX_OK) {
- LOG("Error attempting to set cache policy for PCI registers (res %d)\n", res);
+ LOG(ERROR, "Error attempting to set cache policy for PCI registers (res %d)\n", res);
return res;
}
@@ -229,7 +228,7 @@
constexpr uint32_t CPU_MAP_FLAGS = ZX_VM_FLAG_PERM_READ | ZX_VM_FLAG_PERM_WRITE;
res = mapped_regs_.Map(bar_vmo, bar_info.size, CPU_MAP_FLAGS, DriverVmars::registers());
if (res != ZX_OK) {
- LOG("Error attempting to map registers (res %d)\n", res);
+ LOG(ERROR, "Error attempting to map registers (res %d)\n", res);
return res;
}
@@ -245,24 +244,24 @@
if (res != ZX_OK) {
res = pci_set_irq_mode(&pci_, ZX_PCIE_IRQ_MODE_LEGACY, 1);
if (res != ZX_OK) {
- LOG("Failed to set IRQ mode (%d)!\n", res);
+ LOG(ERROR, "Failed to set IRQ mode (%d)!\n", res);
return res;
} else {
- LOG("Falling back on legacy IRQ mode!\n");
+ LOG(ERROR, "Falling back on legacy IRQ mode!\n");
}
}
ZX_DEBUG_ASSERT(!irq_.is_valid());
res = pci_map_interrupt(&pci_, 0, irq_.reset_and_get_address());
if (res != ZX_OK) {
- LOG("Failed to map IRQ! (res %d)\n", res);
+ LOG(ERROR, "Failed to map IRQ! (res %d)\n", res);
return res;
}
// Enable Bus Mastering so we can DMA data and receive MSIs
res = pci_enable_bus_master(&pci_, true);
if (res != ZX_OK) {
- LOG("Failed to enable PCI bus mastering!\n");
+ LOG(ERROR, "Failed to enable PCI bus mastering!\n");
return res;
}
@@ -285,7 +284,7 @@
"Max stream count mismatch!");
if (!total_stream_cnt || (total_stream_cnt > countof(regs()->stream_desc))) {
- LOG("Invalid stream counts in GCAP register (In %u Out %u Bidir %u; Max %zu)\n",
+ LOG(ERROR, "Invalid stream counts in GCAP register (In %u Out %u Bidir %u; Max %zu)\n",
input_stream_cnt, output_stream_cnt, bidir_stream_cnt, countof(regs()->stream_desc));
return ZX_ERR_INTERNAL;
}
@@ -301,7 +300,7 @@
auto stream = IntelHDAStream::Create(type, stream_id, ®s()->stream_desc[i], pci_bti_);
if (stream == nullptr) {
- LOG("Failed to create HDA stream context %u/%u\n", i, total_stream_cnt);
+ LOG(ERROR, "Failed to create HDA stream context %u/%u\n", i, total_stream_cnt);
return ZX_ERR_NO_MEMORY;
}
@@ -331,7 +330,7 @@
*entry_count = 2;
cmd = HDA_REG_CORBSIZE_CFG_2ENT;
} else {
- LOG("Invalid ring buffer capabilities! (0x%02x)\n", tmp);
+ LOG(ERROR, "Invalid ring buffer capabilities! (0x%02x)\n", tmp);
return ZX_ERR_BAD_STATE;
}
@@ -358,7 +357,7 @@
ZX_CACHE_POLICY_UNCACHED_DEVICE);
if (res != ZX_OK) {
- LOG("Failed to create and map %u bytes for CORB/RIRB command buffers! (res %d)\n",
+ LOG(ERROR, "Failed to create and map %u bytes for CORB/RIRB command buffers! (res %d)\n",
PAGE_SIZE, res);
return res;
}
@@ -375,7 +374,7 @@
constexpr uint32_t HDA_MAP_FLAGS = ZX_BTI_PERM_READ | ZX_BTI_PERM_WRITE;
res = cmd_buf_hda_mem_.Pin(cmd_buf_vmo, pci_bti_, HDA_MAP_FLAGS);
if (res != ZX_OK) {
- LOG("Failed to pin pages for CORB/RIRB command buffers! (res %d)\n", res);
+ LOG(ERROR, "Failed to pin pages for CORB/RIRB command buffers! (res %d)\n", res);
return res;
}
@@ -427,7 +426,7 @@
// our command buffers.
bool gcap_64bit_ok = HDA_REG_GCAP_64OK(REG_RD(®s()->gcap));
if ((cmd_buf_paddr64 >> 32) && !gcap_64bit_ok) {
- LOG("Intel HDA controller does not support 64-bit physical addressing!\n");
+ LOG(ERROR, "Intel HDA controller does not support 64-bit physical addressing!\n");
return ZX_ERR_NOT_SUPPORTED;
}
@@ -494,7 +493,7 @@
minor = REG_RD(®s()->vmin);
if ((1 != major) || (0 != minor)) {
- LOG("Unexpected HW revision %d.%d!\n", major, minor);
+ LOG(ERROR, "Unexpected HW revision %d.%d!\n", major, minor);
return ZX_ERR_NOT_SUPPORTED;
}
@@ -535,7 +534,7 @@
#endif
if (c11_res < 0) {
- LOG("Failed create IRQ thread! (res = %d)\n", c11_res);
+ LOG(ERROR, "Failed create IRQ thread! (res = %d)\n", c11_res);
SetState(State::SHUT_DOWN);
return ZX_ERR_INTERNAL;
}
@@ -567,11 +566,12 @@
// our device.
// Generate a device name and initialize our device structure
- snprintf(debug_tag_, sizeof(debug_tag_), "intel-hda-%03u", id());
+ char dev_name[ZX_DEVICE_NAME_MAX] = { 0 };
+ snprintf(dev_name, sizeof(dev_name), "intel-hda-%03u", id());
device_add_args_t args = {};
args.version = DEVICE_ADD_ARGS_VERSION;
- args.name = debug_tag_;
+ args.name = dev_name;
args.ctx = this;
args.ops = &CONTROLLER_DEVICE_THUNKS;
args.proto_id = ZX_PROTOCOL_IHDA;
diff --git a/system/dev/audio/intel-hda/controller/intel-hda-controller.cpp b/system/dev/audio/intel-hda/controller/intel-hda-controller.cpp
index ee275c1..5bba014 100644
--- a/system/dev/audio/intel-hda/controller/intel-hda-controller.cpp
+++ b/system/dev/audio/intel-hda/controller/intel-hda-controller.cpp
@@ -57,14 +57,10 @@
};
#undef DEV
-void IntelHDAController::PrintDebugPrefix() const {
- printf("[%s] ", debug_tag_);
-}
-
IntelHDAController::IntelHDAController()
: state_(static_cast<StateStorage>(State::STARTING)),
id_(device_id_gen_.fetch_add(1u)) {
- snprintf(debug_tag_, sizeof(debug_tag_), "Unknown IHDA Controller");
+ snprintf(log_prefix_, sizeof(log_prefix_), "IHDA Controller (unknown BDF)");
}
IntelHDAController::~IntelHDAController() {
@@ -245,23 +241,23 @@
ZX_DEBUG_ASSERT(channel != nullptr);
res = channel->Read(&req, sizeof(req), &req_size);
if (res != ZX_OK) {
- DEBUG_LOG("Failed to read client request (res %d)\n", res);
+ LOG(TRACE, "Failed to read client request (res %d)\n", res);
return res;
}
// Sanity checks
if (req_size < sizeof(req.hdr)) {
- DEBUG_LOG("Client request too small to contain header (%u < %zu)\n",
+ LOG(TRACE, "Client request too small to contain header (%u < %zu)\n",
req_size, sizeof(req.hdr));
return ZX_ERR_INVALID_ARGS;
}
// Dispatch
- VERBOSE_LOG("Client Request 0x%04x len %u\n", req.hdr.cmd, req_size);
+ LOG(SPEW, "Client Request 0x%04x len %u\n", req.hdr.cmd, req_size);
switch (req.hdr.cmd) {
case IHDA_CMD_GET_IDS: {
if (req_size != sizeof(req.get_ids)) {
- DEBUG_LOG("Bad GET_IDS request length (%u != %zu)\n",
+ LOG(TRACE, "Bad GET_IDS request length (%u != %zu)\n",
req_size, sizeof(req.get_ids));
return ZX_ERR_INVALID_ARGS;
}
@@ -283,7 +279,7 @@
case IHDA_CONTROLLER_CMD_SNAPSHOT_REGS:
if (req_size != sizeof(req.snapshot_regs)) {
- DEBUG_LOG("Bad SNAPSHOT_REGS request length (%u != %zu)\n",
+ LOG(TRACE, "Bad SNAPSHOT_REGS request length (%u != %zu)\n",
req_size, sizeof(req.snapshot_regs));
return ZX_ERR_INVALID_ARGS;
}
diff --git a/system/dev/audio/intel-hda/controller/intel-hda-controller.h b/system/dev/audio/intel-hda/controller/intel-hda-controller.h
index f3c4cfb..bd34fb2 100644
--- a/system/dev/audio/intel-hda/controller/intel-hda-controller.h
+++ b/system/dev/audio/intel-hda/controller/intel-hda-controller.h
@@ -22,6 +22,7 @@
#include <intel-hda/utils/intel-hda-proto.h>
#include "codec-cmd-job.h"
+#include "debug-logging.h"
#include "intel-hda-codec.h"
#include "pinned-vmo.h"
#include "thread-annotations.h"
@@ -36,10 +37,13 @@
~IntelHDAController();
zx_status_t Init(zx_device_t* pci_dev);
- void PrintDebugPrefix() const;
- const char* dev_name() const { return device_get_name(dev_node_); }
- zx_device_t* dev_node() { return dev_node_; }
- unsigned int id() const { return id_; }
+
+ // one-liner accessors.
+ const char* dev_name() const { return device_get_name(dev_node_); }
+ zx_device_t* dev_node() { return dev_node_; }
+ const zx_pcie_device_info_t& dev_info() const { return pci_dev_info_; }
+ unsigned int id() const { return id_; }
+ const char* log_prefix() const { return log_prefix_; }
// CORB/RIRB
zx_status_t QueueCodecCmd(fbl::unique_ptr<CodecCmdJob>&& job) TA_EXCL(corb_lock_);
@@ -132,8 +136,8 @@
thrd_t irq_thread_;
bool irq_thread_started_ = false;
- // Debug stuff
- char debug_tag_[ZX_DEVICE_NAME_MAX] = { 0 };
+ // Log prefix storage
+ char log_prefix_[LOG_PREFIX_STORAGE] = { 0 };
// Upstream PCI device, protocol interface, and device info.
zx_device_t* pci_dev_ = nullptr;
diff --git a/system/dev/audio/intel-hda/controller/intel-hda-stream.cpp b/system/dev/audio/intel-hda/controller/intel-hda-stream.cpp
index b9a3632..eb921a7 100644
--- a/system/dev/audio/intel-hda/controller/intel-hda-stream.cpp
+++ b/system/dev/audio/intel-hda/controller/intel-hda-stream.cpp
@@ -30,10 +30,6 @@
constexpr uint32_t DMA_ALIGN_MASK = DMA_ALIGN - 1;
} // namespace
-void IntelHDAStream::PrintDebugPrefix() const {
- printf("[IHDA_SD #%u] ", id_);
-}
-
fbl::RefPtr<IntelHDAStream> IntelHDAStream::Create(
Type type,
uint16_t id,
@@ -55,6 +51,17 @@
return ret;
}
+IntelHDAStream::IntelHDAStream(Type type,
+ uint16_t id,
+ hda_stream_desc_regs_t* regs,
+ const fbl::RefPtr<RefCountedBti>& pci_bti)
+ : type_(type),
+ id_(id),
+ regs_(regs),
+ pci_bti_(pci_bti) {
+ snprintf(log_prefix_, sizeof(log_prefix_), "IHDA_SD #%u", id_);
+}
+
IntelHDAStream::~IntelHDAStream() {
ZX_DEBUG_ASSERT(!running_);
}
@@ -77,7 +84,7 @@
ZX_RIGHT_SAME_RIGHTS,
ZX_CACHE_POLICY_UNCACHED_DEVICE);
if (res != ZX_OK) {
- LOG("Failed to create and map %u bytes for stream BDL! (res %d)\n", PAGE_SIZE, res);
+ LOG(ERROR, "Failed to create and map %u bytes for stream BDL! (res %d)\n", PAGE_SIZE, res);
return res;
}
@@ -87,7 +94,7 @@
ZX_DEBUG_ASSERT(pci_bti_ != nullptr);
res = bdl_hda_mem_.Pin(bdl_vmo, pci_bti_, HDA_MAP_FLAGS);
if (res != ZX_OK) {
- LOG("Failed to pin pages for stream BDL! (res %d)\n", res);
+ LOG(ERROR, "Failed to pin pages for stream BDL! (res %d)\n", res);
return res;
}
@@ -141,7 +148,7 @@
regs);
if (res != ZX_OK) {
- GLOBAL_LOG("Failed to place stream descriptor HW into reset! (res %d)\n", res);
+ GLOBAL_LOG(ERROR, "Failed to place stream descriptor HW into reset! (res %d)\n", res);
}
// Leave the reset state. To do this, we...
@@ -162,7 +169,7 @@
regs);
if (res != ZX_OK) {
- GLOBAL_LOG("Failed to release stream descriptor HW from reset! (res %d)\n", res);
+ GLOBAL_LOG(ERROR, "Failed to release stream descriptor HW from reset! (res %d)\n", res);
}
}
@@ -210,8 +217,8 @@
&local_endpoint,
client_endpoint_out);
if (res != ZX_OK) {
- DEBUG_LOG("Failed to create and activate ring buffer channel during SetStreamFormat "
- "(res %d)\n", res);
+ LOG(TRACE, "Failed to create and activate ring buffer channel during SetStreamFormat "
+ "(res %d)\n", res);
return res;
}
@@ -222,7 +229,7 @@
hw_mb();
fifo_depth_ = REG_RD(®s_->fifod);
- DEBUG_LOG("Stream format set 0x%04hx; fifo is %hu bytes deep\n", encoded_fmt_, fifo_depth_);
+ LOG(TRACE, "Stream format set 0x%04hx; fifo is %hu bytes deep\n", encoded_fmt_, fifo_depth_);
// Record our new client channel
fbl::AutoLock channel_lock(&channel_lock_);
@@ -237,18 +244,18 @@
DeactivateLocked();
}
-#define HANDLE_REQ(_ioctl, _payload, _handler, _allow_noack) \
-case _ioctl: \
- if (req_size != sizeof(req._payload)) { \
- DEBUG_LOG("Bad " #_ioctl \
- " response length (%u != %zu)\n", \
- req_size, sizeof(req._payload)); \
- return ZX_ERR_INVALID_ARGS; \
- } \
- if (!_allow_noack && (req.hdr.cmd & AUDIO_FLAG_NO_ACK)) { \
- DEBUG_LOG("NO_ACK flag not allowed for " #_ioctl "\n"); \
- return ZX_ERR_INVALID_ARGS; \
- } \
+#define HANDLE_REQ(_ioctl, _payload, _handler, _allow_noack) \
+case _ioctl: \
+ if (req_size != sizeof(req._payload)) { \
+ LOG(TRACE, "Bad " #_ioctl \
+ " response length (%u != %zu)\n", \
+ req_size, sizeof(req._payload)); \
+ return ZX_ERR_INVALID_ARGS; \
+ } \
+ if (!_allow_noack && (req.hdr.cmd & AUDIO_FLAG_NO_ACK)) { \
+ LOG(TRACE, "NO_ACK flag not allowed for " #_ioctl "\n"); \
+ return ZX_ERR_INVALID_ARGS; \
+ } \
return _handler(req._payload);
zx_status_t IntelHDAStream::ProcessClientRequest(dispatcher::Channel* channel) {
zx_status_t res;
@@ -276,21 +283,21 @@
ZX_DEBUG_ASSERT(channel != nullptr);
res = channel->Read(&req, sizeof(req), &req_size);
if (res != ZX_OK) {
- DEBUG_LOG("Failed to read client request (res %d)\n", res);
+ LOG(TRACE, "Failed to read client request (res %d)\n", res);
return res;
}
// Sanity check the request, then dispatch it to the appropriate handler.
if (req_size < sizeof(req.hdr)) {
- DEBUG_LOG("Client request too small to contain header (%u < %zu)\n",
+ LOG(TRACE, "Client request too small to contain header (%u < %zu)\n",
req_size, sizeof(req.hdr));
return ZX_ERR_INVALID_ARGS;
}
- VERBOSE_LOG("Client Request (cmd 0x%04x tid %u) len %u\n",
- req.hdr.cmd,
- req.hdr.transaction_id,
- req_size);
+ LOG(SPEW, "Client Request (cmd 0x%04x tid %u) len %u\n",
+ req.hdr.cmd,
+ req.hdr.transaction_id,
+ req_size);
if (req.hdr.transaction_id == AUDIO_INVALID_TRANSACTION_ID)
return ZX_ERR_INVALID_ARGS;
@@ -303,7 +310,7 @@
HANDLE_REQ(AUDIO_RB_CMD_START, start, ProcessStartLocked, false);
HANDLE_REQ(AUDIO_RB_CMD_STOP, stop, ProcessStopLocked, false);
default:
- DEBUG_LOG("Unrecognized command ID 0x%04x\n", req.hdr.cmd);
+ LOG(TRACE, "Unrecognized command ID 0x%04x\n", req.hdr.cmd);
return ZX_ERR_INVALID_ARGS;
}
}
@@ -315,7 +322,7 @@
// request.
fbl::AutoLock channel_lock(&channel_lock_);
if (channel == channel_.get()) {
- DEBUG_LOG("Client closed channel to stream\n");
+ LOG(TRACE, "Client closed channel to stream\n");
DeactivateLocked();
}
}
@@ -338,7 +345,7 @@
// that their stream was ruined and that they need to restart it.
if (sts & (HDA_SD_REG_STS8_FIFOE | HDA_SD_REG_STS8_DESE)) {
REG_CLR_BITS(®s_->ctl_sts.w, HDA_SD_REG_CTRL_RUN);
- LOG("Fatal stream error, shutting down DMA! (IRQ status 0x%02x)\n", sts);
+ LOG(ERROR, "Fatal stream error, shutting down DMA! (IRQ status 0x%02x)\n", sts);
}
if (irq_channel_ == nullptr)
@@ -378,7 +385,7 @@
// Release any assigned ring buffer.
ReleaseRingBufferLocked();
- DEBUG_LOG("Stream deactivated\n");
+ LOG(TRACE, "Stream deactivated\n");
}
zx_status_t IntelHDAStream::ProcessGetFifoDepthLocked(
@@ -391,7 +398,7 @@
// We don't know what our FIFO depth is going to be if our format has not
// been set yet.
if (bytes_per_frame_ == 0) {
- DEBUG_LOG("Bad state (not configured) while getting fifo depth.\n");
+ LOG(TRACE, "Bad state (not configured) while getting fifo depth.\n");
resp.result = ZX_ERR_BAD_STATE;
resp.fifo_depth = 0;
} else {
@@ -417,9 +424,9 @@
// We cannot change buffers while we are running, and we cannot create a
// buffer if our format has not been set yet.
if (running_ || (bytes_per_frame_ == 0)) {
- DEBUG_LOG("Bad state %s%s while setting buffer.",
- running_ ? "(running)" : "",
- bytes_per_frame_ == 0 ? "(not configured)" : "");
+ LOG(TRACE, "Bad state %s%s while setting buffer.",
+ running_ ? "(running)" : "",
+ bytes_per_frame_ == 0 ? "(not configured)" : "");
resp.result = ZX_ERR_BAD_STATE;
goto finished;
}
@@ -433,10 +440,10 @@
if ((req.min_ring_buffer_frames == 0) ||
(tmp > fbl::numeric_limits<uint32_t>::max()) ||
(req.notifications_per_ring > MAX_BDL_LENGTH)) {
- DEBUG_LOG("Invalid client args while setting buffer "
- "(min frames %u, notif/ring %u)\n",
- req.min_ring_buffer_frames,
- req.notifications_per_ring);
+ LOG(TRACE, "Invalid client args while setting buffer "
+ "(min frames %u, notif/ring %u)\n",
+ req.min_ring_buffer_frames,
+ req.notifications_per_ring);
resp.result = ZX_ERR_INVALID_ARGS;
goto finished;
}
@@ -448,7 +455,7 @@
// Attempt to allocate a VMO for the ring buffer.
resp.result = zx::vmo::create(rb_size, 0, &ring_buffer_vmo);
if (resp.result != ZX_OK) {
- DEBUG_LOG("Failed to create %u byte VMO for ring buffer (res %d)\n",
+ LOG(TRACE, "Failed to create %u byte VMO for ring buffer (res %d)\n",
rb_size, resp.result);
goto finished;
}
@@ -461,14 +468,15 @@
resp.result = pinned_ring_buffer_.Pin(ring_buffer_vmo, pci_bti_, hda_rights);
if (resp.result != ZX_OK) {
- DEBUG_LOG("Failed to commit and pin pages for %u bytes in ring buffer VMO (res %d)\n",
+ LOG(TRACE, "Failed to commit and pin pages for %u bytes in ring buffer VMO (res %d)\n",
rb_size, resp.result);
goto finished;
}
ZX_DEBUG_ASSERT(pinned_ring_buffer_.region_count() >= 1);
if (pinned_ring_buffer_.region_count() > MAX_BDL_LENGTH) {
- LOG("IntelHDA stream ring buffer is too fragmented (%u regions) to construct a valid BDL\n",
+ LOG(ERROR,
+ "IntelHDA stream ring buffer is too fragmented (%u regions) to construct a valid BDL\n",
pinned_ring_buffer_.region_count());
resp.result = ZX_ERR_INTERNAL;
goto finished;
@@ -490,7 +498,7 @@
&client_rb_handle);
if (resp.result != ZX_OK) {
- DEBUG_LOG("Failed duplicate ring buffer VMO handle! (res %d)\n", resp.result);
+ LOG(TRACE, "Failed duplicate ring buffer VMO handle! (res %d)\n", resp.result);
goto finished;
}
@@ -518,7 +526,7 @@
const auto& r = pinned_ring_buffer_.region(region_num);
if (r.size > fbl::numeric_limits<uint32_t>::max()) {
- DEBUG_LOG("VMO region too large! (%" PRIu64" bytes)", r.size);
+ LOG(TRACE, "VMO region too large! (%" PRIu64 " bytes)", r.size);
resp.result = ZX_ERR_INTERNAL;
goto finished;
}
@@ -568,22 +576,22 @@
bdl()[entry - 1].flags = IntelHDABDLEntry::IOC_FLAG;
}
- if (DEBUG_LOGGING) {
- DEBUG_LOG("DMA Scatter/Gather used %u entries for %u/%u bytes of ring buffer\n",
- entry, amt_done, rb_size);
+ if (zxlog_level_enabled(TRACE)) {
+ LOG(TRACE, "DMA Scatter/Gather used %u entries for %u/%u bytes of ring buffer\n",
+ entry, amt_done, rb_size);
for (uint32_t i = 0; i < entry; ++i) {
- DEBUG_LOG("[%2u] : %016" PRIx64 " - 0x%04x %sIRQ\n",
- i,
- bdl()[i].address,
- bdl()[i].length,
- bdl()[i].flags ? "" : "NO ");
+ LOG(TRACE, "[%2u] : %016" PRIx64 " - 0x%04x %sIRQ\n",
+ i,
+ bdl()[i].address,
+ bdl()[i].length,
+ bdl()[i].flags ? "" : "NO ");
}
}
if (amt_done < rb_size) {
ZX_DEBUG_ASSERT(entry == MAX_BDL_LENGTH);
- DEBUG_LOG("Ran out of BDL entires after %u/%u bytes of ring buffer\n",
- amt_done, rb_size);
+ LOG(TRACE, "Ran out of BDL entires after %u/%u bytes of ring buffer\n",
+ amt_done, rb_size);
resp.result = ZX_ERR_INTERNAL;
goto finished;
}
@@ -620,7 +628,7 @@
// We cannot start unless we have configured the ring buffer and are not already started.
bool ring_buffer_valid = pinned_ring_buffer_.region_count() >= 1;
if (!ring_buffer_valid || running_) {
- DEBUG_LOG("Bad state during start request %s%s.\n",
+ LOG(TRACE, "Bad state during start request %s%s.\n",
!ring_buffer_valid ? "(ring buffer not configured)" : "",
running_ ? "(already running)" : "");
resp.result = ZX_ERR_BAD_STATE;
diff --git a/system/dev/audio/intel-hda/controller/intel-hda-stream.h b/system/dev/audio/intel-hda/controller/intel-hda-stream.h
index ee0b20d..313867e 100644
--- a/system/dev/audio/intel-hda/controller/intel-hda-stream.h
+++ b/system/dev/audio/intel-hda/controller/intel-hda-stream.h
@@ -17,6 +17,7 @@
#include <intel-hda/utils/intel-hda-registers.h>
#include "pinned-vmo.h"
+#include "debug-logging.h"
#include "thread-annotations.h"
#include "utils.h"
@@ -42,11 +43,12 @@
hda_stream_desc_regs_t* regs,
const fbl::RefPtr<RefCountedBti>& pci_bti);
- Type type() const { return type_; }
- Type configured_type() const { return configured_type_; }
- uint8_t tag() const { return tag_; }
- uint16_t id() const { return id_; }
- uint16_t GetKey() const { return id(); }
+ const char* log_prefix() const { return log_prefix_; }
+ Type type() const { return type_; }
+ Type configured_type() const { return configured_type_; }
+ uint8_t tag() const { return tag_; }
+ uint16_t id() const { return id_; }
+ uint16_t GetKey() const { return id(); }
zx_status_t SetStreamFormat(const fbl::RefPtr<dispatcher::ExecutionDomain>& domain,
uint16_t encoded_fmt,
@@ -62,12 +64,9 @@
IntelHDAStream(Type type,
uint16_t id,
hda_stream_desc_regs_t* regs,
- const fbl::RefPtr<RefCountedBti>& pci_bti)
- : type_(type), id_(id), regs_(regs), pci_bti_(pci_bti) {}
+ const fbl::RefPtr<RefCountedBti>& pci_bti);
~IntelHDAStream();
- void PrintDebugPrefix() const;
-
zx_status_t Initialize();
void DeactivateLocked() TA_REQ(channel_lock_);
@@ -118,6 +117,9 @@
Type configured_type_;
uint8_t tag_;
+ // Log prefix storage
+ char log_prefix_[LOG_PREFIX_STORAGE] = { 0 };
+
// A reference to our controller's BTI. We will need to this to grant the
// controller access to the BDLs and the ring buffers that this stream needs
// to operate.
diff --git a/system/dev/audio/intel-hda/controller/irq-thread.cpp b/system/dev/audio/intel-hda/controller/irq-thread.cpp
index 334bd2e..e6d7523 100644
--- a/system/dev/audio/intel-hda/controller/irq-thread.cpp
+++ b/system/dev/audio/intel-hda/controller/irq-thread.cpp
@@ -20,7 +20,7 @@
void IntelHDAController::WakeupIRQThread() {
ZX_DEBUG_ASSERT(irq_.is_valid());
- VERBOSE_LOG("Waking up IRQ thread\n");
+ LOG(SPEW, "Waking up IRQ thread\n");
irq_.signal(ZX_INTERRUPT_SLOT_USER, zx::time(0));
}
@@ -34,10 +34,10 @@
// TODO(johngro) : Fix this. The IRQ API has changed out from under us, and
// we cannot currently wait with a timeout.
- VERBOSE_LOG("IRQ thread waiting on IRQ\n");
+ LOG(SPEW, "IRQ thread waiting on IRQ\n");
uint64_t slots;
irq_.wait(&slots);
- VERBOSE_LOG("IRQ thread woke up\n");
+ LOG(SPEW, "IRQ thread woke up\n");
// Disable IRQs at the device level
REG_WR(®s()->intctl, 0u);
@@ -81,7 +81,7 @@
ZX_DEBUG_ASSERT(!pending);
- VERBOSE_LOG("RIRB has %u pending responses; WP is @%u\n", rirb_snapshot_cnt_, rirb_wr_ptr);
+ LOG(SPEW, "RIRB has %u pending responses; WP is @%u\n", rirb_snapshot_cnt_, rirb_wr_ptr);
if (rirbsts & HDA_REG_RIRBSTS_OIS) {
// TODO(johngro) : Implement retry behavior for codec command and
@@ -107,8 +107,8 @@
// be a reasonable retry system at the codec driver level.
//
// Right now, we just log the error, ack the IRQ and move on.
- LOG("CRITICAL ERROR: controller overrun detected while "
- "attempting to write to response input ring buffer.\n");
+ LOG(ERROR, "CRITICAL ERROR: controller overrun detected while "
+ "attempting to write to response input ring buffer.\n");
}
}
@@ -126,22 +126,22 @@
/* Sanity checks */
if (caddr >= countof(codecs_)) {
- LOG("Received %ssolicited response with illegal codec address (%u) "
- "[0x%08x, 0x%08x]\n",
- resp.unsolicited() ? "un" : "", caddr, resp.data, resp.data_ex);
+ LOG(ERROR, "Received %ssolicited response with illegal codec address (%u) "
+ "[0x%08x, 0x%08x]\n",
+ resp.unsolicited() ? "un" : "", caddr, resp.data, resp.data_ex);
continue;
}
auto codec = GetCodec(caddr);
if (!codec) {
- LOG("Received %ssolicited response for non-existent codec address (%u) "
- "[0x%08x, 0x%08x]\n",
- resp.unsolicited() ? "un" : "", caddr, resp.data, resp.data_ex);
+ LOG(ERROR, "Received %ssolicited response for non-existent codec address (%u) "
+ "[0x%08x, 0x%08x]\n",
+ resp.unsolicited() ? "un" : "", caddr, resp.data, resp.data_ex);
continue;
}
- DEBUG_LOG("RX[%2u]: 0x%08x%s\n",
- caddr, resp.data, resp.unsolicited() ? " (unsolicited)" : "");
+ LOG(TRACE, "RX[%2u]: 0x%08x%s\n",
+ caddr, resp.data, resp.unsolicited() ? " (unsolicited)" : "");
if (!resp.unsolicited()) {
fbl::unique_ptr<CodecCmdJob> job;
@@ -153,7 +153,8 @@
// job waiting at the head of the in-flight queue which triggered
// it.
if (in_flight_corb_jobs_.is_empty()) {
- LOG("Received solicited response for codec address (%u) [0x%08x, 0x%08x] "
+ LOG(ERROR,
+ "Received solicited response for codec address (%u) [0x%08x, 0x%08x] "
"but no in-flight job is waiting for it\n",
caddr, resp.data, resp.data_ex);
continue;
@@ -169,7 +170,8 @@
} else {
auto codec = GetCodec(caddr);
if (!codec) {
- LOG("Received unsolicited response for non-existent codec address (%u) "
+ LOG(ERROR,
+ "Received unsolicited response for non-existent codec address (%u) "
"[0x%08x, 0x%08x]\n", caddr, resp.data, resp.data_ex);
continue;
}
@@ -202,8 +204,8 @@
zx_status_t IntelHDAController::QueueCodecCmd(fbl::unique_ptr<CodecCmdJob>&& job) {
ZX_DEBUG_ASSERT(job != nullptr);
- DEBUG_LOG("TX: Codec ID %u Node ID %hu Verb 0x%05x\n",
- job->codec_id(), job->nid(), job->verb().val);
+ LOG(TRACE, "TX: Codec ID %u Node ID %hu Verb 0x%05x\n",
+ job->codec_id(), job->nid(), job->verb().val);
// Enter the lock, then check out the state of the ring buffer. If the
// buffer is full, or if there are already commands backed up into the
@@ -253,8 +255,8 @@
// assert in debug builds. In release builds, we simply ack the
// interrupt and move on.
//
- LOG("CRITICAL ERROR: controller encountered an unrecoverable "
- "error attempting to read from system memory!\n");
+ LOG(ERROR, "CRITICAL ERROR: controller encountered an unrecoverable "
+ "error attempting to read from system memory!\n");
ZX_DEBUG_ASSERT(false);
}
@@ -264,7 +266,7 @@
// While we have room in the CORB, and still have commands which are waiting
// to be sent out, move commands from the pending queue into the in-flight
// queue.
- VERBOSE_LOG("CORB has space for %u commands; WP is @%u\n", corb_space_, corb_wr_ptr_);
+ LOG(SPEW, "CORB has space for %u commands; WP is @%u\n", corb_space_, corb_wr_ptr_);
while (corb_space_ && !pending_corb_jobs_.is_empty()) {
auto job = pending_corb_jobs_.pop_front();
@@ -272,7 +274,7 @@
in_flight_corb_jobs_.push_back(fbl::move(job));
}
- VERBOSE_LOG("Update CORB WP; WP is @%u\n", corb_wr_ptr_);
+ LOG(SPEW, "Update CORB WP; WP is @%u\n", corb_wr_ptr_);
// Update the CORB write pointer.
CommitCORBLocked();
@@ -393,7 +395,7 @@
ProcessCORB();
}
- DEBUG_LOG("IRQ thread exiting!\n");
+ LOG(TRACE, "IRQ thread exiting!\n");
// Disable all interrupts and place the device into reset on our way out.
REG_WR(®s()->intctl, 0u);
diff --git a/system/dev/audio/intel-hda/controller/utils.cpp b/system/dev/audio/intel-hda/controller/utils.cpp
index 073fb0f..6e2000f 100644
--- a/system/dev/audio/intel-hda/controller/utils.cpp
+++ b/system/dev/audio/intel-hda/controller/utils.cpp
@@ -79,7 +79,7 @@
((MAX_CONTROLLERS * MAX_SIZE_PER_CONTROLLER) +
(((MAX_CONTROLLERS * MAX_ALLOCS_PER_CONTROLLER) - 1) * (512u << 10)));
- GLOBAL_DEBUG_LOG("Allocating 0x%zx byte VMAR for registers.\n", VMAR_SIZE);
+ GLOBAL_LOG(TRACE, "Allocating 0x%zx byte VMAR for registers.\n", VMAR_SIZE);
registers_ = fbl::VmarManager::Create(VMAR_SIZE);
if (registers_ == nullptr) {
return ZX_ERR_NO_MEMORY;
