From ac840390602910a2c69703f628e01ed28154a3ab Mon Sep 17 00:00:00 2001 From: Tom Burdick Date: Thu, 14 Jul 2022 15:52:20 -0500 Subject: [PATCH] tests: intel_adsp: Silence the hda tests Uses a macro with a define flag to enable register dumps on the DSP side. On the python side a simple booling flag. The default disabled both debug flags and makes the tests considerably quieter. Signed-off-by: Tom Burdick --- soc/xtensa/intel_adsp/tools/cavstool.py | 13 +++--- tests/boards/intel_adsp/hda/src/dma.c | 52 ++++++++-------------- tests/boards/intel_adsp/hda/src/smoke.c | 58 ++++++++++--------------- tests/boards/intel_adsp/hda/src/tests.h | 17 ++++++++ 4 files changed, 67 insertions(+), 73 deletions(-) diff --git a/soc/xtensa/intel_adsp/tools/cavstool.py b/soc/xtensa/intel_adsp/tools/cavstool.py index 344919f51f4..9387b4671a7 100755 --- a/soc/xtensa/intel_adsp/tools/cavstool.py +++ b/soc/xtensa/intel_adsp/tools/cavstool.py @@ -37,9 +37,8 @@ PACKET_HEADER_FORMAT_FW = 'I 42s 32s' HEADER_SZ = 78 -logging.basicConfig() +logging.basicConfig(level=logging.INFO) log = logging.getLogger("cavs-fw") -log.setLevel(logging.INFO) PAGESZ = 4096 HUGEPAGESZ = 2 * 1024 * 1024 @@ -168,12 +167,12 @@ class HDAStream: return (mem, hugef, phys_addr + bdl_off, phys_addr+dpib_off, 2) def debug(self): - log.info("HDA %d: PPROC %d, CTL 0x%x, LPIB 0x%x, BDPU 0x%x, BDPL 0x%x, CBL 0x%x, LVI 0x%x", + log.debug("HDA %d: PPROC %d, CTL 0x%x, LPIB 0x%x, BDPU 0x%x, BDPL 0x%x, CBL 0x%x, LVI 0x%x", self.stream_id, (hda.PPCTL >> self.stream_id) & 1, self.regs.CTL, self.regs.LPIB, self.regs.BDPU, self.regs.BDPL, self.regs.CBL, self.regs.LVI) - log.info(" FIFOW %d, FIFOS %d, FMT %x, FIFOL %d, DPIB %d, EFIFOS %d", + log.debug(" FIFOW %d, FIFOS %d, FMT %x, FIFOL %d, DPIB %d, EFIFOS %d", self.regs.FIFOW & 0x7, self.regs.FIFOS, self.regs.FMT, self.regs.FIFOL, self.dbg0.DPIB, self.dbg0.EFIFOS) - log.info(" status: FIFORDY %d, DESE %d, FIFOE %d, BCIS %d", + log.debug(" status: FIFORDY %d, DESE %d, FIFOE %d, BCIS %d", (self.regs.STS >> 5) & 1, (self.regs.STS >> 4) & 1, (self.regs.STS >> 3) & 1, (self.regs.STS >> 2) & 1) def reset(self): @@ -850,6 +849,8 @@ def get_host_ip(): ap = argparse.ArgumentParser(description="DSP loader/logger tool") ap.add_argument("-q", "--quiet", action="store_true", help="No loader output, just DSP logging") +ap.add_argument("-v", "--verbose", action="store_true", + help="More loader output, DEBUG logging level") ap.add_argument("-l", "--log-only", action="store_true", help="Don't load firmware, just show log output") ap.add_argument("-n", "--no-history", action="store_true", @@ -862,6 +863,8 @@ args = ap.parse_args() if args.quiet: log.setLevel(logging.WARN) +elif args.verbose: + log.setLevel(logging.DEBUG) if args.fw_file: fw_file = args.fw_file diff --git a/tests/boards/intel_adsp/hda/src/dma.c b/tests/boards/intel_adsp/hda/src/dma.c index 87e1b017328..5afc6981e8f 100644 --- a/tests/boards/intel_adsp/hda/src/dma.c +++ b/tests/boards/intel_adsp/hda/src/dma.c @@ -72,16 +72,14 @@ void test_hda_host_in_dma(void) channel = dma_request_channel(dma, NULL); zassert_true(channel >= 0, "Expected a valid DMA channel"); - - printk("dma channel: "); intel_adsp_hda_dbg("host_in", HDA_HOST_IN_BASE, channel); + hda_dump_regs(HOST_IN, channel, "dma channel"); hda_ipc_msg(CAVS_HOST_DEV, IPCCMD_HDA_RESET, channel, IPC_TIMEOUT); - - printk("host reset: "); intel_adsp_hda_dbg("host_in", HDA_HOST_IN_BASE, channel); + hda_dump_regs(HOST_IN, channel, "host reset"); hda_ipc_msg(CAVS_HOST_DEV, IPCCMD_HDA_CONFIG, channel | (DMA_BUF_SIZE << 8), IPC_TIMEOUT); - printk("host config: "); intel_adsp_hda_dbg("host_in", HDA_HOST_IN_BASE, channel); + hda_dump_regs(HOST_IN, channel, "host config"); struct dma_block_config block_cfg = { @@ -96,22 +94,20 @@ void test_hda_host_in_dma(void) }; res = dma_config(dma, channel, &dma_cfg); - printk("dsp dma config: "); intel_adsp_hda_dbg("host_in", HDA_HOST_IN_BASE, channel); + hda_dump_regs(HOST_IN, channel, "dsp dma config"); zassert_ok(res, "Expected dma config to succeed"); res = dma_start(dma, channel); - printk("dsp dma start: "); intel_adsp_hda_dbg("host_in", HDA_HOST_IN_BASE, channel); + hda_dump_regs(HOST_IN, channel, "dsp dma start"); zassert_ok(res, "Expected dma start to succeed"); hda_ipc_msg(CAVS_HOST_DEV, IPCCMD_HDA_START, channel, IPC_TIMEOUT); - - printk("host start: "); intel_adsp_hda_dbg("host_in", HDA_HOST_IN_BASE, channel); + hda_dump_regs(HOST_IN, channel, "host start"); for (uint32_t i = 0; i < TRANSFER_COUNT; i++) { res = dma_reload(dma, channel, 0, 0, DMA_BUF_SIZE); zassert_ok(res, "Expected dma reload to succeed"); - printk("dsp dma reload: "); - intel_adsp_hda_dbg("host_in", HDA_HOST_IN_BASE, channel); + hda_dump_regs(HOST_IN, channel, "dsp dma reload"); struct dma_status status; int j; @@ -124,8 +120,7 @@ void test_hda_host_in_dma(void) } k_busy_wait(100); } - printk("dsp read write equal after %d uS: ", j*100); - intel_adsp_hda_dbg("host_in", HDA_HOST_IN_BASE, channel); + hda_dump_regs(HOST_IN, channel, "dsp read write equal after %d uS", j*100); last_msg_cnt = msg_cnt; hda_ipc_msg(CAVS_HOST_DEV, IPCCMD_HDA_VALIDATE, channel, @@ -165,18 +160,15 @@ void test_hda_host_out_dma(void) channel = dma_request_channel(dma, NULL); zassert_true(channel >= 0, "Expected a valid DMA channel"); - - printk("dma channel: "); intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, channel); + hda_dump_regs(HOST_OUT, channel, "dma request channel"); hda_ipc_msg(CAVS_HOST_DEV, IPCCMD_HDA_RESET, (channel + 7), IPC_TIMEOUT); - - printk("host reset: "); intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, channel); + hda_dump_regs(HOST_OUT, channel, "host reset"); hda_ipc_msg(CAVS_HOST_DEV, IPCCMD_HDA_CONFIG, (channel + 7) | (DMA_BUF_SIZE << 8), IPC_TIMEOUT); - - printk("host config: "); intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, channel); + hda_dump_regs(HOST_OUT, channel, "host config"); struct dma_block_config block_cfg = { .block_size = DMA_BUF_SIZE, @@ -190,29 +182,24 @@ void test_hda_host_out_dma(void) }; res = dma_config(dma, channel, &dma_cfg); - printk("dsp dma config: "); intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, channel); + hda_dump_regs(HOST_OUT, channel, "dsp dma config"); zassert_ok(res, "Expected dma config to succeed"); res = dma_start(dma, channel); - printk("dsp dma start: "); intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, channel); + hda_dump_regs(HOST_OUT, channel, "dsp dma start"); zassert_ok(res, "Expected dma start to succeed"); hda_ipc_msg(CAVS_HOST_DEV, IPCCMD_HDA_START, (channel + 7), IPC_TIMEOUT); - - printk("host start: "); - intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, channel); + hda_dump_regs(HOST_OUT, channel, "host start"); for (uint32_t i = 0; i < TRANSFER_COUNT; i++) { hda_ipc_msg(CAVS_HOST_DEV, IPCCMD_HDA_SEND, (channel + 7) | (DMA_BUF_SIZE << 8), IPC_TIMEOUT); - - printk("host send: "); - intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, channel); + hda_dump_regs(HOST_OUT, channel, "host send"); /* TODO add a dma_poll() style call for xfer ready/complete maybe? */ WAIT_FOR(intel_adsp_hda_buf_full(HDA_HOST_OUT_BASE, channel), 10000, k_msleep(1)); - printk("dsp wait for full: "); - intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, channel); + hda_dump_regs(HOST_OUT, channel, "dsp wait for full"); #if (IS_ENABLED(CONFIG_KERNEL_COHERENCE)) zassert_true(arch_mem_coherent(dma_buf), "Buffer is unexpectedly incoherent!"); @@ -226,7 +213,7 @@ void test_hda_host_out_dma(void) is_ramp = true; for (int j = 0; j < DMA_BUF_SIZE; j++) { - printk("dma_buf[%d] = %d\n", j, dma_buf[j]); + /* printk("dma_buf[%d] = %d\n", j, dma_buf[j]); */ /* DEBUG HELPER */ if (dma_buf[j] != j) { is_ramp = false; } @@ -235,8 +222,7 @@ void test_hda_host_out_dma(void) res = dma_reload(dma, channel, 0, 0, DMA_BUF_SIZE); zassert_ok(res, "Expected dma reload to succeed"); - printk("dsp dma reload: "); - intel_adsp_hda_dbg("host_out", HDA_HOST_IN_BASE, channel); + hda_dump_regs(HOST_OUT, channel, "dsp dma reload"); } hda_ipc_msg(CAVS_HOST_DEV, IPCCMD_HDA_RESET, (channel + 7), IPC_TIMEOUT); @@ -245,5 +231,5 @@ void test_hda_host_out_dma(void) res = dma_stop(dma, channel); zassert_ok(res, "Expected dma stop to succeed"); - printk("dsp dma stop: "); intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, channel); + hda_dump_regs(HOST_OUT, channel, "dsp dma stop"); } diff --git a/tests/boards/intel_adsp/hda/src/smoke.c b/tests/boards/intel_adsp/hda/src/smoke.c index fad8cbf6ccd..b6000ec0cef 100644 --- a/tests/boards/intel_adsp/hda/src/smoke.c +++ b/tests/boards/intel_adsp/hda/src/smoke.c @@ -67,36 +67,31 @@ void test_hda_host_in_smoke(void) #endif intel_adsp_hda_init(HDA_HOST_IN_BASE, STREAM_ID); - printk("dsp init: "); intel_adsp_hda_dbg("host_in", HDA_HOST_IN_BASE, STREAM_ID); + hda_dump_regs(HOST_IN, STREAM_ID, "dsp init"); hda_ipc_msg(CAVS_HOST_DEV, IPCCMD_HDA_RESET, STREAM_ID, IPC_TIMEOUT); - printk("host reset: "); - intel_adsp_hda_dbg("host_in", HDA_HOST_IN_BASE, STREAM_ID); + hda_dump_regs(HOST_IN, STREAM_ID, "host reset"); hda_ipc_msg(CAVS_HOST_DEV, IPCCMD_HDA_CONFIG, STREAM_ID | (HDA_BUF_SIZE << 8), IPC_TIMEOUT); - printk("host config: "); - intel_adsp_hda_dbg("host_in", HDA_HOST_IN_BASE, STREAM_ID); + hda_dump_regs(HOST_IN, STREAM_ID, "host config"); res = intel_adsp_hda_set_buffer(HDA_HOST_IN_BASE, STREAM_ID, hda_buf, HDA_BUF_SIZE); - printk("dsp set_buffer: "); intel_adsp_hda_dbg("host_in", HDA_HOST_IN_BASE, STREAM_ID); + hda_dump_regs(HOST_IN, STREAM_ID, "dsp set_buffer"); zassert_ok(res, "Expected set buffer to succeed"); intel_adsp_hda_enable(HDA_HOST_IN_BASE, STREAM_ID); - printk("dsp enable: "); intel_adsp_hda_dbg("host_in", HDA_HOST_IN_BASE, STREAM_ID); + hda_dump_regs(HOST_IN, STREAM_ID, "dsp enable"); hda_ipc_msg(CAVS_HOST_DEV, IPCCMD_HDA_START, STREAM_ID, IPC_TIMEOUT); - - printk("host start: "); - intel_adsp_hda_dbg("host_in", HDA_HOST_IN_BASE, STREAM_ID); + hda_dump_regs(HOST_IN, STREAM_ID, "host start"); for (uint32_t i = 0; i < TRANSFER_COUNT; i++) { intel_adsp_hda_host_commit(HDA_HOST_IN_BASE, STREAM_ID, HDA_BUF_SIZE); - printk("dsp inc_pos: "); intel_adsp_hda_dbg("host_in", HDA_HOST_IN_BASE, STREAM_ID); + hda_dump_regs(HOST_IN, STREAM_ID, "dsp inc_pos"); WAIT_FOR(intel_adsp_hda_wp_rp_eq(HDA_HOST_IN_BASE, STREAM_ID), 10000, k_msleep(1)); - printk("dsp wp_rp_eq: "); - intel_adsp_hda_dbg("host_in", HDA_HOST_IN_BASE, STREAM_ID); + hda_dump_regs(HOST_IN, STREAM_ID, "dsp wp == rp"); last_msg_cnt = msg_cnt; hda_ipc_msg(CAVS_HOST_DEV, IPCCMD_HDA_VALIDATE, STREAM_ID, @@ -108,7 +103,10 @@ void test_hda_host_in_smoke(void) } hda_ipc_msg(CAVS_HOST_DEV, IPCCMD_HDA_RESET, STREAM_ID, IPC_TIMEOUT); + hda_dump_regs(HOST_IN, STREAM_ID, "host reset"); + intel_adsp_hda_disable(HDA_HOST_IN_BASE, STREAM_ID); + hda_dump_regs(HOST_IN, STREAM_ID, "dsp disable"); } /* @@ -130,29 +128,24 @@ void test_hda_host_out_smoke(void) printk("Using buffer of size %d at addr %p\n", HDA_BUF_SIZE, hda_buf); intel_adsp_hda_init(HDA_HOST_OUT_BASE, STREAM_ID); - printk("dsp init: "); intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, STREAM_ID); + hda_dump_regs(HOST_OUT, STREAM_ID, "dsp init"); hda_ipc_msg(CAVS_HOST_DEV, IPCCMD_HDA_RESET, (STREAM_ID + 7), IPC_TIMEOUT); - printk("host reset: "); - intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, STREAM_ID); + hda_dump_regs(HOST_OUT, STREAM_ID, "host reset"); hda_ipc_msg(CAVS_HOST_DEV, IPCCMD_HDA_CONFIG, (STREAM_ID + 7) | (HDA_BUF_SIZE << 8), IPC_TIMEOUT); - - printk("host config: "); - intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, STREAM_ID); + hda_dump_regs(HOST_OUT, STREAM_ID, "host config"); res = intel_adsp_hda_set_buffer(HDA_HOST_OUT_BASE, STREAM_ID, hda_buf, HDA_BUF_SIZE); - printk("dsp set buffer: "); intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, STREAM_ID); + hda_dump_regs(HOST_OUT, STREAM_ID, "dsp set buffer"); zassert_ok(res, "Expected set buffer to succeed"); hda_ipc_msg(CAVS_HOST_DEV, IPCCMD_HDA_START, (STREAM_ID + 7), IPC_TIMEOUT); - printk("host start: "); - intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, STREAM_ID); + hda_dump_regs(HOST_OUT, STREAM_ID, "host start"); intel_adsp_hda_enable(HDA_HOST_OUT_BASE, STREAM_ID); - printk("dsp enable: "); - intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, STREAM_ID); + hda_dump_regs(HOST_OUT, STREAM_ID, "dsp enable"); for (uint32_t i = 0; i < TRANSFER_COUNT; i++) { for (int j = 0; j < HDA_BUF_SIZE; j++) { @@ -161,16 +154,14 @@ void test_hda_host_out_smoke(void) hda_ipc_msg(CAVS_HOST_DEV, IPCCMD_HDA_SEND, (STREAM_ID + 7) | (HDA_BUF_SIZE << 8), IPC_TIMEOUT); - printk("host send: "); - intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, STREAM_ID); + hda_dump_regs(HOST_OUT, STREAM_ID, "host send"); WAIT_FOR(intel_adsp_hda_buf_full(HDA_HOST_OUT_BASE, STREAM_ID), 10000, k_msleep(1)); - printk("dsp wait for full: "); - intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, STREAM_ID); + hda_dump_regs(HOST_OUT, STREAM_ID, "dsp wait for full"); #if (IS_ENABLED(CONFIG_KERNEL_COHERENCE)) - zassert_true(arch_mem_coherent(hda_buf), "Buffer is unexpectedly incoherent!"); + zassert_true(arch_mem_coherent(hda_buf), "Buffer is unexpectedly incoherent!"); #else /* The buffer is in the cached address range and must be invalidated * prior to reading. @@ -189,17 +180,14 @@ void test_hda_host_out_smoke(void) zassert_true(is_ramp, "Expected data to be a ramp"); intel_adsp_hda_host_commit(HDA_HOST_OUT_BASE, STREAM_ID, HDA_BUF_SIZE); - printk("dsp inc pos: "); - intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, STREAM_ID); + hda_dump_regs(HOST_OUT, STREAM_ID, "dsp inc pos"); } hda_ipc_msg(CAVS_HOST_DEV, IPCCMD_HDA_RESET, (STREAM_ID + 7), IPC_TIMEOUT); - - printk("host reset: "); - intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, STREAM_ID); + hda_dump_regs(HOST_OUT, STREAM_ID, "host reset"); intel_adsp_hda_disable(HDA_HOST_OUT_BASE, STREAM_ID); - printk("dsp disable: "); intel_adsp_hda_dbg("host_out", HDA_HOST_OUT_BASE, STREAM_ID); + hda_dump_regs(HOST_OUT, STREAM_ID, "dsp disable"); } diff --git a/tests/boards/intel_adsp/hda/src/tests.h b/tests/boards/intel_adsp/hda/src/tests.h index e41053e3662..9cadbf580fe 100644 --- a/tests/boards/intel_adsp/hda/src/tests.h +++ b/tests/boards/intel_adsp/hda/src/tests.h @@ -15,6 +15,23 @@ void test_hda_host_in_smoke(void); void test_hda_host_out_smoke(void); void test_hda_host_in_dma(void); + +/* Turn this define on to see register dumps after each step */ +#define INTEL_ADSP_HDA_DBG 0 + +#define CONCAT3(x, y, z) x ## y ## z + +#define STREAM_SET_BASE(stream_set) CONCAT3(HDA_, stream_set, _BASE) +#define STREAM_SET_NAME(stream_set) STRINGIFY(stream_set) + +#if INTEL_ADSP_HDA_DBG +#define hda_dump_regs(stream_set, stream_id, ...) \ + printk(__VA_ARGS__); printk(": "); \ + intel_adsp_hda_dbg(STREAM_SET_NAME(stream_set), STREAM_SET_BASE(stream_set), stream_id) +#else +#define hda_dump_regs(stream_set, stream_id, msg, ...) do {} while (0) +#endif + static inline void hda_ipc_msg(const struct device *dev, uint32_t data, uint32_t ext, k_timeout_t timeout) {