[00:01:07.136,350] ipc: ipc_cmd: rx : 0x11000002|0x0 [00:01:07.136,366] pipe: pipeline_new: pipeline new pipe_id 0 priority 0 [00:01:07.143,011] ipc: ipc_cmd: rx : 0x40000004|0x306 [00:01:07.143,053] ipc: buffer_new: buffer new size 0x100 id 0.0 flags 0x0 [00:01:07.143,088] dai_intel_dmic: dai_dmic_probe: dmic_probe() [00:01:07.143,108] dma: dma_get: dma_get() ID 0 sref = 1 busy channels 0 [00:01:07.143,123] ipc: dai_config: comp:0 0x40000 dai_config() dai type = 2 index = 1 dd 0x400ea3c0 [00:01:07.143,136] dai_intel_dmic: dai_dmic_set_config: dmic_set_config() [00:01:07.143,143] dai_intel_dmic_nhlt: dai_dmic_set_config_nhlt: dmic_set_config_nhlt(): OUTCONTROL0 = 00388043 [00:01:07.143,151] dai_intel_dmic_nhlt: dai_dmic_set_config_nhlt: tie=0, sip=0, finit=0, fci=0 [00:01:07.143,158] dai_intel_dmic_nhlt: dai_dmic_set_config_nhlt: bfth=3, of=2, ipm=1, th=3 [00:01:07.143,165] dai_intel_dmic_nhlt: dai_dmic_set_config_nhlt: ipms1=0, ipms2=0, ipms3=0, ipms4=0 [00:01:07.143,170] dai_intel_dmic_nhlt: dai_dmic_set_config_nhlt: ipms_mode=1 [00:01:07.143,178] dai_intel_dmic_nhlt: dai_dmic_set_config_nhlt: dmic_set_config_nhlt(): OUTCONTROL1 = 00388043 [00:01:07.143,185] dai_intel_dmic_nhlt: dai_dmic_set_config_nhlt: tie=0, sip=0, finit=0, fci=0 [00:01:07.143,191] dai_intel_dmic_nhlt: dai_dmic_set_config_nhlt: bfth=3, of=2, ipm=1, th=3 [00:01:07.143,198] dai_intel_dmic_nhlt: dai_dmic_set_config_nhlt: ipms1=0, ipms2=0, ipms3=0, ipms4=0 [00:01:07.143,203] dai_intel_dmic_nhlt: dai_dmic_set_config_nhlt: ipms_mode=1 [00:01:07.143,211] dai_intel_dmic_nhlt: dai_dmic_set_config_nhlt: dmic_set_config_nhlt(): OUTCONTROL1 = 02388043 [00:01:07.143,221] dai_intel_dmic_nhlt: dai_dmic_set_config_nhlt: dmic_set_config_nhlt(): clkdiv = 16, mcic = 25, mfir_b = 6, len = 247 [00:01:07.143,256] dai_intel_dmic_nhlt: dai_dmic_set_config_nhlt: dmic_set_config_nhlt(): clkdiv = 16, mcic = 25, mfir_b = 6, len = 247 [00:01:07.143,288] dai_intel_dmic_nhlt: dai_dmic_set_config_nhlt: dmic_set_config_nhlt(): rate = 16000, channels = 2, format = 2 [00:01:07.143,295] dai_intel_dmic_nhlt: dai_dmic_set_config_nhlt: dmic_set_config_nhlt(): io_clk 38400000, rate_div 2400 [00:01:07.143,303] dai_intel_dmic_nhlt: dai_dmic_set_config_nhlt: dmic_set_config_nhlt(): enable0 3, enable1 0 [00:01:07.143,311] pipe: pipeline_connect: comp:0 0x40000 connect buffer 0 as sink [00:01:07.143,806] ipc: ipc_cmd: rx : 0x4000000e|0xa [00:01:07.143,821] kpb: kpb_new: kpb_new() [00:01:07.144,328] ipc: ipc_cmd: rx : 0x11010002|0x0 [00:01:07.144,338] pipe: pipeline_new: pipeline new pipe_id 1 priority 0 [00:01:07.144,598] ipc: ipc_cmd: rx : 0x40000009|0x10010 [00:01:07.144,635] module_adapter: module_init: comp:1 0x90000 module_init() start [00:01:07.144,648] module_adapter: module_init: comp:1 0x90000 module_init() done [00:01:07.145,601] ipc: ipc_cmd: rx : 0x4000000d|0x1000f [00:01:07.145,625] kd_test: test_keyword_new: test_keyword_new() [00:01:07.146,646] ipc: ipc_cmd: rx : 0x11020001|0x0 [00:01:07.146,655] pipe: pipeline_new: pipeline new pipe_id 2 priority 0 [00:01:07.147,661] ipc: ipc_cmd: rx : 0x40010004|0x20015 [00:01:07.147,703] ipc: buffer_new: buffer new size 0x100 id 2.0 flags 0x0 [00:01:07.147,748] dma: dma_get: dma_get() ID 0 sref = 1 busy channels 0 [00:01:07.147,768] pipe: pipeline_connect: comp:2 0x40001 connect buffer 0 as source [00:01:07.148,156] ipc: ipc_cmd: rx : 0x4500000e|0x8010004 [00:01:07.148,168] ipc: buffer_new: buffer new size 0x100 id 0.65536 flags 0x0 [00:01:07.148,193] pipe: pipeline_connect: comp:0 0xe0000 connect buffer 65536 as sink [00:01:07.148,200] pipe: pipeline_connect: comp:2 0x40001 connect buffer 65536 as source [00:01:07.148,391] ipc: ipc_cmd: rx : 0x45000009|0xd [00:01:07.148,403] ipc: buffer_new: buffer new size 0x80 id 1.0 flags 0x0 [00:01:07.148,423] pipe: pipeline_connect: comp:1 0x90000 connect buffer 0 as sink [00:01:07.148,431] pipe: pipeline_connect: comp:1 0xd0000 connect buffer 0 as[00:01:07.154,098] ipc: ipc_cmd: rx : 0x13000004|0x1 [00:01:07.154,143] pipe: pipeline_prepare: pipe:2 0x0 pipe prepare [00:01:07.154,166] pipe: pipeline_trigger: pipe:2 0x0 pipe trigger cmd 7 [00:01:07.154,181] ll_schedule: zephyr_ll_task_schedule_common: task add 0xa00ec740 0x20180U priority 0 flags 0x0 [00:01:07.154,206] ll_schedule: zephyr_domain_register: zephyr_domain_register domain->type 1 domain->clk 3 domain->ticks_per_ms 38400 period 1000 [00:01:07.154,218] kd_test: test_keyword_set_params: comp:1 0xd0000 test_keyword_set_params() [00:01:07.154,236] pipe: pipeline_prepare: pipe:1 0x0 pipe prepare [00:01:07.154,280] host_comp: host_get_copy_bytes_normal: comp:2 0x40001 no bytes to copy, 0 avail in buffer, 256 free in DMA [00:01:07.154,310] kd_test: test_keyword_prepare: comp:1 0xd0000 test_keyword_prepare() [00:01:07.154,330] selector: selector_prepare: comp:1 0x90000 selector_prepare() [00:01:07.154,336] selector: selector_params: comp:1 0x90000 selector_params() [00:01:07.154,350] selector: selector_prepare: comp:1 0x90000 selector_prepare(): sourceb->schannels = 2 [00:01:07.154,358] selector: selector_prepare: comp:1 0x90000 selector_prepare(): sinkb->channels = 1 [00:01:07.154,378] pipe: pipeline_trigger: pipe:1 0x0 pipe trigger cmd 7 [00:01:07.154,390] ll_schedule: zephyr_ll_task_schedule_common: task add 0xa00ec900 0x20180U priority 0 flags 0x0 [00:01:07.154,410] ipc: ipc_dai_data_config: comp:0 0x40000 dai_data_config() dai type = 2 index = 1 dd 0x400ea3c0 [00:01:07.154,418] ipc: ipc_dai_data_config: comp:0 0x40000 dai_data_config() burst_elems = 8 [00:01:07.154,446] dai_comp: dai_capture_params: comp:0 0x40000 dai_capture_params() src_dev = 1 stream_id = 0 src_width = 4 dest_width = 4 [00:01:07.154,455] dai_comp: dai_capture_params: comp:0 0x40000 dai_capture_params() fifo 0x10108 [00:01:07.154,480] pipe: pipeline_prepare: pipe:0 0x0 pipe prepare [00:01:07.154,498] kpb: kpb_allocate_history_buffer: kpb_allocate_history_buffer() [00:01:07.154,515] kpb: kpb_allocate_history_buffer: kpb new memory block: 268800 [00:01:07.154,521] kpb: kpb_allocate_history_buffer: kpb_allocate_history_buffer(): allocated 268800 bytes [00:01:07.154,528] kpb: kpb_reset_history_buffer: kpb_reset_history_buffer() [00:01:07.154,535] kpb: kpb_clear_history_buffer: kpb_clear_history_buffer() [00:01:07.154,756] dai_comp: dai_prepare: comp:0 0x40000 dai_prepare() [00:01:07.154,766] dai_comp: dai_config_prepare: comp:0 0x40000 dai_config_prepare(), channel = 0 [00:01:07.154,776] dai_comp: dai_config_prepare: comp:0 0x40000 dai_config_prepare(): new configured dma channel index 0 [00:01:07.154,803] pipe: pipeline_trigger: pipe:0 0x0 pipe trigger cmd 7 [00:01:07.154,813] ll_schedule: zephyr_ll_task_schedule_common: task add 0xa00ecfc0 0x20180U priority 0 flags 0x0 [00:01:07.155,280] host_comp: host_get_copy_bytes_normal: comp:2 0x40001 no bytes to copy, 0 avail in buffer, 256 free in DMA [00:01:07.155,290] kd_test: test_keyword_trigger: comp:1 0xd0000 test_keyword_trigger() [00:01:07.155,301] kd_test: test_keyword_trigger: comp:1 0xd0000 test_keyword_trigger() [00:01:07.155,315] module_adapter: comp:1 0x90000 module_process() error 1: for comp 589824 [00:01:07.155,323] module_adapter: comp:1 0x90000 module_adapter_copy() error 1: module processing failed [00:01:07.155,331] kpb: kpb_trigger: comp:0 0xe0000 kpb_trigger() [00:01:07.155,343] kpb: kpb_trigger: comp:0 0xe0000 kpb_trigger() [00:01:07.155,360] dai_intel_dmic: dai_dmic_start: dmic_start(), dmic->fifo_b [00:01:07.155,368] dai_intel_dmic: dai_dmic_update_bits: dai_dmic_update_bits base 10000, reg 100, mask 6000000, value 4000000 [00:01:07.155,375] dai_intel_dmic: dai_dmic_start: dmic_start(), pdm0 mic_a = 1, mic_b = 1 [00:01:07.155,383] dai_intel_dmic: dai_dmic_update_bits: dai_dmic_upda[00:01:07.163,331] dai_comp: comp:0 0x40000 dai_copy(): nothing to copy [00:01:07.163,346] kpb: comp:0 0xe0000 kpb_copy(): nothing to copy sink->free 0 source->avail 256 [00:01:07.164,335] host_comp: host_get_copy_bytes_normal: comp:2 0x40001 no bytes to copy, 0 avail in buffer, 256 free in DMA [00:01:07.164,346] dai_comp: comp:0 0x40000 dai_copy(): nothing to copy [00:01:07.164,361] kpb: comp:0 0xe0000 kpb_copy(): nothing to copy sink->free 0 source->avail 256 [00:01:07.165,305] host_comp: host_get_copy_bytes_normal: comp:2 0x40001 no bytes to copy, 0 avail in buffer, 256 free in DMA [00:01:07.165,320] dai_comp: comp:0 0x40000 dai_copy(): Copy_bytes 0 + free bytes 32 < period bytes 128, possible glitch [00:01:07.165,331] dai_comp: comp:0 0x40000 dai_copy(): nothing to copy [00:01:07.165,346] kpb: comp:0 0xe0000 kpb_copy(): nothing to copy sink->free 0 source->avail 256 [00:01:07.166,285] host_comp: host_get_copy_bytes_normal: comp:2 0x40001 no bytes to copy, 0 avail in buffer, 256 free in DMA [00:01:07.166,293] dma_dw_common: xrun detected [00:01:07.166,301] dai_comp: comp:0 0x40000 dai_report_xrun(): overrun due to no space available [00:01:07.166,310] component: comp:0 0x40000 comp_overrun(): sink->free = 0, copy_bytes = 0 [00:01:07.166,321] pipe: pipeline_trigger: pipe:0 0x0 pipe trigger cmd 6 [00:01:07.166,336] pipe: pipe:0 0x0 pipeline_copy(): ret = -61, start->comp.id = 262144, dir = 0 [00:01:07.166,343] pipe: pipeline_reset: pipe:0 0x0 pipe reset [00:01:07.166,350] dai_comp: dai_reset: comp:0 0x40000 dai_reset() [00:01:07.166,360] ipc: dai_dma_release: comp:0 0x40000 dai_config(): Component is in active state. Ignore resetting [00:01:07.166,405] component: comp:0 0x40000 comp_set_state(): wrong state = 5, COMP_TRIGGER_RESET [00:01:07.166,413] component: comp:0 0x40000 comp_set_state(): wrong state = 5, COMP_TRIGGER_RESET [00:01:07.166,423] pipe: pipe:0 0x0 pipeline_task(): xrun recovery failed! pipeline is stopped. [00:01:07.166,428] ll_schedule: zephyr_ll_task_done: task complete 0xa00ecfc0 0x20180U [00:01:07.166,435] ll_schedule: zephyr_ll_task_done: num_tasks 2 total_num_tasks 2 [00:01:07.167,308] pipe: pipeline_reset: pipe:2 0x0 pipe reset [00:01:07.167,350] component: comp:2 0x40001 comp_set_state(): wrong state = 5, COMP_TRIGGER_RESET [00:01:07.167,358] ll_schedule: zephyr_ll_task_done: task complete 0xa00ec740 0x20180U [00:01:07.167,365] ll_schedule: zephyr_ll_task_done: num_tasks 1 total_num_tasks 1 [00:01:07.167,375] ll_schedule: zephyr_domain_unregister: zephyr_domain_unregister domain->type 1 domain->clk 3 [00:01:12.895,883] ipc: ipc_cmd: rx : 0x13000003|0x1 [00:01:12.896,308] ipc: ipc_cmd: rx : 0x13000002|0x1 [00:01:12.896,758] ipc: ipc_cmd: rx : 0x4600000e|0x9 [00:01:12.896,768] pipe: pipeline_disconnect: comp:0 0xe0000 disconnect buffer 0 as sink [00:01:12.896,776] pipe: pipeline_disconnect: comp:1 0x90000 disconnect buffer 0 as source [00:01:12.902,766] ipc: ipc_cmd: rx : 0x4600000e|0x8010004 [00:01:12.902,785] pipe: pipeline_disconnect: comp:0 0xe0000 disconnect buffer 65536 as sink [00:01:12.902,793] pipe: pipeline_disconnect: comp:2 0x40001 disconnect buffer 65536 as source [00:01:12.903,230] ipc: ipc_cmd: rx : 0x12000000|0x0 [00:01:12.903,240] pipe: pipeline_disconnect: comp:0 0x40000 disconnect buffer 0 as sink [00:01:12.903,268] dma: dma_put: dma_put(), dma = 0x400d3ea0, sref = 0 [00:01:12.903,275] dai_intel_dmic: dai_dmic_remove: dmic_remove() [00:01:12.903,285] dai_intel_dmic: dai_dmic_remove: dmic_remove(), dmic_active_fifos_mask = 0x2, dmic_pause_mask = 0x0 [00:01:12.903,356] pipe: pipeline_disconnect: comp:0 0xe0000 disconnect buffer 0 as source [00:01:12.903,385] ipc: ipc_comp_free(): comp id: 917504 state is 5 cannot be freed [00:01:12.903,390] ipc: ipc_pipeline_free(): module free () failed [00:01:12.903,396] ipc: ipc4: FW_GEN_MSG failed with err 12 [00:01:12.903,861] ipc: ipc_cmd: rx : 0x12010000|0x0 [00:01:12.903,871] pipe: pipeline_disconnect: comp:1 0x90000 disconnect buffer 0 as sink [00:01:12.903,906] pipe: pipeline_disconnect: comp:1 0xd0000 disconnect buffer 0 as source [00:01:12.903,935] ipc: ipc_comp_free(): comp id: 851968 state is 5 cannot be freed [00:01:12.903,941] ipc: ipc_pipeline_free(): module free () failed [00:01:12.903,946] ipc: ipc4: FW_GEN_MSG failed with err 12 [00:01:12.904,393] ipc: ipc_cmd: rx : 0x12020000|0x0 [00:01:12.904,406] host_comp: host_free: comp:2 0x40001 host_free() [00:01:12.904,418] dma: dma_put: dma_put(), dma = 0x400d3f30, sref = 0 [00:01:12.904,486] pipe: pipeline_free: pipe:2 0x0 pipeline_free()