[00:00:00.044,388] init: print_version_banner: FW ABI 0x301a000 DBG ABI 0x5003000 tags SOF:v2.5-stable-branch-516-g5f118b761bf0 zephyr:v3.4.0-rc2 src hash 0xb35a70bd (ref hash 0xb35a70bd) [00:00:00.044,415] clock: clock_set_freq: clock 0 set freq 400000000Hz freq_idx 2 [00:00:00.044,431] clock: clock_set_freq: clock 1 set freq 400000000Hz freq_idx 2 [00:00:00.044,450] clock: clock_set_freq: clock 2 set freq 400000000Hz freq_idx 2 *** Booting Zephyr OS build v3.4.0-rc2 *** [00:00:00.044,690] main: main: SOF on intel_adsp_ace15_mtpm [00:00:00.044,703] main: main: SOF initialized [00:00:00.045,663] ipc: ipc_cmd: rx : 0x44000000|0x31400008 [00:00:00.046,228] ipc: ipc_cmd: rx : 0x44000000|0x3060004c [00:00:00.047,741] ipc: ipc_cmd: rx : 0x11000007|0x0 [00:00:00.047,755] pipe: pipeline_new: pipeline new pipe_id 0 priority 0 [00:00:00.048,313] ipc: ipc_cmd: rx : 0x40000004|0x15 [00:00:00.048,373] dma: dma_get: dma_get() ID 0 sref = 1 busy channels 0 [00:00:00.049,140] ipc: ipc_cmd: rx : 0x40000006|0x10 [00:00:00.049,846] ipc: ipc_cmd: rx : 0x44000006|0x30000018 [00:00:00.050,335] ipc: ipc_cmd: rx : 0x40000002|0xa [00:00:00.051,110] ipc: ipc_cmd: rx : 0x11010006|0x0 [00:00:00.051,123] pipe: pipeline_new: pipeline new pipe_id 1 priority 0 [00:00:00.051,836] ipc: ipc_cmd: rx : 0x40000003|0x1000a [00:00:00.052,420] ipc: ipc_cmd: rx : 0x40010006|0x10010 [00:00:00.053,183] ipc: ipc_cmd: rx : 0x44010006|0x30000018 [00:00:00.053,933] ipc: ipc_cmd: rx : 0x40010004|0x1002f [00:00:00.053,998] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power: dai_ssp_pm_runtime_en_ssp_power en_ssp_power index 0 [00:00:00.054,008] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power: dai_ssp_pm_runtime_en_ssp_power I2SLCTL [00:00:00.054,020] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 28000, reg 8, mask 80, value 80 [00:00:00.054,060] dma: dma_get: dma_get() ID 0 sref = 1 busy channels 0 [00:00:00.054,075] ipc: dai_config: comp:1 0x40001 dai_config() dai type = 1 index = 0 dd 0x40115980 [00:00:00.054,095] dai_intel_ssp: dai_ssp_parse_aux_data: dai_ssp_parse_aux_data link clock_source 1 [00:00:00.054,111] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config sscr0 = 0xc1d0077f, sscr1 = 0xd0700004, ssto = 0x00000000, sspsp = 0x2200000 [00:00:00.054,125] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config sscr2 = 0x00004002, sspsp2 = 0x00000000, sscr3 = 0x07070000 [00:00:00.054,138] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config ssioc = 0x00000020, ssrsa = 0x00000003, sstsa = 0x00000003 [00:00:00.054,151] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 28000, reg 4, mask 300000, value 300000 [00:00:00.054,163] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 28000, reg 0, mask 80, value 80 [00:00:00.054,810] ipc: ipc_cmd: rx : 0x45000004|0x6 [00:00:00.054,826] ipc: buffer_new: buffer new size 0x300 id 0.0 flags 0x0 [00:00:00.054,850] pipe: pipeline_connect: comp:0 0x40000 connect buffer 0 as sink [00:00:00.054,865] pipe: pipeline_connect: comp:0 0x60000 connect buffer 0 as source [00:00:00.057,360] ipc: ipc_cmd: rx : 0x45000006|0x2 [00:00:00.057,378] ipc: buffer_new: buffer new size 0x300 id 0.0 flags 0x0 [00:00:00.057,401] pipe: pipeline_connect: comp:0 0x60000 connect buffer 0 as sink [00:00:00.057,415] pipe: pipeline_connect: comp:0 0x20000 connect buffer 0 as source [00:00:00.058,106] ipc: ipc_cmd: rx : 0x45000002|0x3 [00:00:00.058,135] ipc: buffer_new: buffer new size 0x300 id 0.0 flags 0x0 [00:00:00.058,158] pipe: pipeline_connect: comp:0 0x20000 connect buffer 0 as sink [00:00:00.058,173] pipe: pipeline_connect: comp:1 0x30000 connect buffer 0 as source [00:00:00.058,858] ipc: ipc_cmd: rx : 0x45000003|0x10006 [00:00:00.058,886] ipc: buffer_new: buffer new size 0x300 id 1.0 flags 0x0 [00:00:00.058,911] pipe: pipeline_connect: comp:1 0x30000 connect buffer 0 as sink [00:00:00.058,925] pipe: pipeline_connect: comp:1 0x60001 connect buffer 0 as source [00:00:00.059,351] ipc: ipc_cmd: rx : 0x45010006|0x10004 [00:00:00.059,370] ipc: buffer_new: buffer new size 0x300 id 1.0 flags 0x0 [00:00:00.059,393] pipe: pipeline_connect: comp:1 0x60001 connect buffer 0 as sink [00:00:00.059,406] pipe: pipeline_connect: comp:1 0x40001 connect buffer 0 as source [00:00:00.060,808] ipc: ipc_cmd: rx : 0x47000000|0x0 [00:00:00.061,713] ipc: ipc_cmd: rx : 0x11020007|0x200000 [00:00:00.061,760] pipe: pipeline_new: pipeline new pipe_id 2 priority 0 [00:00:00.062,301] ipc: ipc_cmd: rx : 0x40020004|0x2020015 [00:00:00.062,375] dma: dma_get: dma_get() ID 0 sref = 2 busy channels 0 [00:00:00.063,208] ipc: ipc_cmd: rx : 0x40020006|0x2020010 [00:00:00.064,028] ipc: ipc_cmd: rx : 0x44020006|0x30000018 [00:00:00.064,531] ipc: ipc_cmd: rx : 0x40010002|0x202000a [00:00:00.065,106] ipc: ipc_cmd: rx : 0x11030006|0x200000 [00:00:00.065,151] pipe: pipeline_new: pipeline new pipe_id 3 priority 0 [00:00:00.065,583] ipc: ipc_cmd: rx : 0x40010003|0x203000a [00:00:00.066,248] ipc: ipc_cmd: rx : 0x40030006|0x2030010 [00:00:00.067,001] ipc: ipc_cmd: rx : 0x44030006|0x30000018 [00:00:00.067,523] ipc: ipc_cmd: rx : 0x40030004|0x203002f [00:00:00.067,618] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power: dai_ssp_pm_runtime_en_ssp_power en_ssp_power index 2 [00:00:00.067,756] dai_intel_ssp: dai_ssp_poll_for_register_delay poll timeout reg 165892 mask 1024 val 0 us 125 [00:00:00.067,780] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power warning: timeout [00:00:00.067,788] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power: dai_ssp_pm_runtime_en_ssp_power I2SLCTL [00:00:00.067,800] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 2a000, reg 8, mask 80, value 80 [00:00:00.067,826] dma: dma_get: dma_get() ID 0 sref = 1 busy channels 0 [00:00:00.067,843] ipc: dai_config: comp:3 0x40003 dai_config() dai type = 1 index = 2 dd 0x40119400 [00:00:00.067,863] dai_intel_ssp: dai_ssp_parse_aux_data: dai_ssp_parse_aux_data link clock_source 1 [00:00:00.067,880] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config sscr0 = 0xc1d0077f, sscr1 = 0xd0700004, ssto = 0x00000000, sspsp = 0x2200000 [00:00:00.067,896] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config sscr2 = 0x00004002, sspsp2 = 0x00000000, sscr3 = 0x07070000 [00:00:00.067,910] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config ssioc = 0x00000020, ssrsa = 0x00000003, sstsa = 0x00000003 [00:00:00.067,923] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 2a000, reg 4, mask 300000, value 300000 [00:00:00.067,935] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 2a000, reg 0, mask 80, value 80 [00:00:00.068,620] ipc: ipc_cmd: rx : 0x45020004|0x20006 [00:00:00.068,673] ipc: buffer_new: buffer new size 0x300 id 2.0 flags 0x0 [00:00:00.068,698] pipe: pipeline_connect: comp:2 0x40002 connect buffer 0 as sink [00:00:00.068,711] pipe: pipeline_connect: comp:2 0x60002 connect buffer 0 as source [00:00:00.069,456] ipc: ipc_cmd: rx : 0x45020006|0x10002 [00:00:00.069,508] ipc: buffer_new: buffer new size 0x300 id 2.0 flags 0x0 [00:00:00.069,533] pipe: pipeline_connect: comp:2 0x60002 connect buffer 0 as sink [00:00:00.069,550] pipe: pipeline_connect: comp:2 0x20001 connect buffer 0 as source [00:00:00.070,365] ipc: ipc_cmd: rx : 0x45010002|0x10003 [00:00:00.070,418] ipc: buffer_new: buffer new size 0x300 id 2.0 flags 0x0 [00:00:00.070,443] pipe: pipeline_connect: comp:2 0x20001 connect buffer 0 as sink [00:00:00.070,456] pipe: pipeline_connect: comp:3 0x30001 connect buffer 0 as source [00:00:00.071,036] ipc: ipc_cmd: rx : 0x45010003|0x30006 [00:00:00.071,090] ipc: buffer_new: buffer new size 0x300 id 3.0 flags 0x0 [00:00:00.071,115] pipe: pipeline_connect: comp:3 0x30001 connect buffer 0 as sink [00:00:00.071,130] pipe: pipeline_connect: comp:3 0x60003 connect buffer 0 as source [00:00:00.071,403] ipc: ipc_cmd: rx : 0x45030006|0x30004 [00:00:00.071,493] ipc: buffer_new: buffer new size 0x300 id 3.0 flags 0x0 [00:00:00.071,518] pipe: pipeline_connect: comp:3 0x60003 connect buffer 0 as sink [00:00:00.071,531] pipe: pipeline_connect: comp:3 0x40003 connect buffer 0 as source [00:00:00.073,066] ipc: ipc_cmd: rx : 0x13000003|0x1 [00:00:00.073,166] ipc: ipc_pipeline_complete(): no scheduling component specified, use comp 131073 [00:00:00.073,811] ipc: ipc_cmd: rx : 0x13000004|0x1 [00:00:00.073,901] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 2 [00:00:00.073,910] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 172048 [00:00:00.073,918] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 6 [00:00:00.073,933] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:00.073,953] dai_comp: dai_playback_params: comp:3 0x40003 dai_playback_params() dest_dev = 6 stream_id = 0 src_width = 4 dest_width = 4 [00:00:00.073,965] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 2 [00:00:00.073,973] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 172048 [00:00:00.073,981] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 6 [00:00:00.073,990] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:00.074,101] pipe: pipeline_trigger: pipe:3 0x0 pipe trigger cmd 7 [00:00:00.074,123] ll_schedule: zephyr_ll_task_schedule_common: task add 0xa011b740 0x201b0U priority 0 flags 0x0 [00:00:00.074,166] ll_schedule: zephyr_domain_register: zephyr_domain_register domain->type 1 domain->clk 3 domain->ticks_per_ms 38400 period 1000 [00:00:00.074,273] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 2 [00:00:00.074,281] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 172048 [00:00:00.074,290] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 6 [00:00:00.074,300] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:00.074,311] dai_intel_ssp: dai_ssp_pre_start: dai_ssp_pre_start [00:00:00.074,345] dma_intel_adsp_gpdma: intel_adsp_gpdma_power_on: intel_adsp_gpdma_power_on: dma dma@7d000 initialized [00:00:00.074,380] dai_intel_ssp: dai_ssp_start: dai_ssp_start [00:00:00.074,393] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 2a000, reg 30, mask 100, value 100 [00:00:00.074,580] mixer: mixin_prepare: comp:2 0x20001 mixin_prepare() [00:00:00.074,615] pipe: pipeline_trigger: pipe:2 0x0 pipe trigger cmd 7 [00:00:00.074,638] ll_schedule: zephyr_ll_task_schedule_common: task add 0xa011c040 0x201b0U priority 0 flags 0x0 [00:00:00.075,450] host_comp: host_get_copy_bytes_normal: comp:2 0x40002 no bytes to copy, available samples: 0, free_samples: 192 [00:00:00.076,340] host_comp: host_get_copy_bytes_normal: comp:2 0x40002 no bytes to copy, available samples: 0, free_samples: 192 [00:00:00.077,340] host_comp: host_get_copy_bytes_normal: comp:2 0x40002 no bytes to copy, available samples: 0, free_samples: 192 [00:00:00.078,180] ipc: ipc_cmd: rx : 0x47000000|0x0 [00:00:00.079,038] ipc: ipc_cmd: rx : 0x11040007|0x100000 [00:00:00.079,093] pipe: pipeline_new: pipeline new pipe_id 4 priority 0 [00:00:00.079,708] ipc: ipc_cmd: rx : 0x13000003|0x1 [00:00:00.079,763] ipc: ipc_pipeline_complete(): no scheduling component specified, use comp 131072 [00:00:00.080,138] ipc: ipc_cmd: rx : 0x13000004|0x1 [00:00:00.080,208] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 0 [00:00:00.080,216] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 163856 [00:00:00.080,226] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 2 [00:00:00.080,236] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:00.080,273] dai_comp: dai_playback_params: comp:1 0x40001 dai_playback_params() dest_dev = 2 stream_id = 0 src_width = 4 dest_width = 4 [00:00:00.080,283] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 0 [00:00:00.080,291] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 163856 [00:00:00.080,300] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 2 [00:00:00.080,310] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:00.080,415] pipe: pipeline_trigger: pipe:1 0x0 pipe trigger cmd 7 [00:00:00.080,436] ll_schedule: zephyr_ll_task_schedule_common: task add 0xa011d100 0x201b0U priority 0 flags 0x0 [00:00:00.080,466] ll_schedule: zephyr_domain_register: zephyr_domain_register domain->type 1 domain->clk 3 domain->ticks_per_ms 38400 period 1000 [00:00:00.080,571] mixer: mixin_prepare: comp:0 0x20000 mixin_prepare() [00:00:00.080,605] pipe: pipeline_trigger: pipe:0 0x0 pipe trigger cmd 7 [00:00:00.080,628] ll_schedule: zephyr_ll_task_schedule_common: task add 0xa011d9c0 0x201b0U priority 0 flags 0x0 [00:00:00.081,281] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 0 [00:00:00.081,290] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 163856 [00:00:00.081,300] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 2 [00:00:00.081,308] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:00.081,320] dai_intel_ssp: dai_ssp_pre_start: dai_ssp_pre_start [00:00:00.081,355] dma_intel_adsp_gpdma: intel_adsp_gpdma_power_on: intel_adsp_gpdma_power_on: dma dma@7c000 initialized [00:00:00.081,403] dai_intel_ssp: dai_ssp_start: dai_ssp_start [00:00:00.081,415] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 28000, reg 30, mask 100, value 100 [00:00:00.081,615] host_comp: host_get_copy_bytes_normal: comp:0 0x40000 no bytes to copy, available samples: 0, free_samples: 192 [00:00:00.082,458] ipc: ipc_cmd: rx : 0x40040004|0x1040015 [00:00:00.082,538] dma: dma_get: dma_get() ID 0 sref = 3 busy channels 0 [00:00:00.083,440] ipc: ipc_cmd: rx : 0x40040006|0x1040010 [00:00:00.084,836] ipc: ipc_cmd: rx : 0x44040006|0x30000018 [00:00:00.085,451] ipc: ipc_cmd: rx : 0x40020002|0x104000a [00:00:00.086,083] ipc: ipc_cmd: rx : 0x11050006|0x100000 [00:00:00.086,131] pipe: pipeline_new: pipeline new pipe_id 5 priority 0 [00:00:00.086,855] ipc: ipc_cmd: rx : 0x40020003|0x105000a [00:00:00.087,423] ipc: ipc_cmd: rx : 0x40050006|0x1050010 [00:00:00.088,081] ipc: ipc_cmd: rx : 0x44050006|0x30000018 [00:00:00.088,958] ipc: ipc_cmd: rx : 0x40050004|0x105002f [00:00:00.089,066] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power: dai_ssp_pm_runtime_en_ssp_power en_ssp_power index 1 [00:00:00.089,205] dai_intel_ssp: dai_ssp_poll_for_register_delay poll timeout reg 165892 mask 512 val 0 us 125 [00:00:00.089,230] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power warning: timeout [00:00:00.089,238] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power: dai_ssp_pm_runtime_en_ssp_power I2SLCTL [00:00:00.089,301] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 29000, reg 8, mask 80, value 80 [00:00:00.089,318] dma: dma_get: dma_get() ID 0 sref = 2 busy channels 0 [00:00:00.089,335] ipc: dai_config: comp:5 0x40005 dai_config() dai type = 1 index = 1 dd 0x4011f900 [00:00:00.089,355] dai_intel_ssp: dai_ssp_parse_aux_data: dai_ssp_parse_aux_data link clock_source 1 [00:00:00.089,371] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config sscr0 = 0xc1d0077f, sscr1 = 0xd0700004, ssto = 0x00000000, sspsp = 0x2200000 [00:00:00.089,386] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config sscr2 = 0x00004002, sspsp2 = 0x00000000, sscr3 = 0x07070000 [00:00:00.089,400] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config ssioc = 0x00000020, ssrsa = 0x00000003, sstsa = 0x00000003 [00:00:00.089,413] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 29000, reg 4, mask 300000, value 300000 [00:00:00.089,425] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 29000, reg 0, mask 80, value 80 [00:00:00.091,441] ipc: ipc_cmd: rx : 0x45040004|0x40006 [00:00:00.091,503] ipc: buffer_new: buffer new size 0x300 id 4.0 flags 0x0 [00:00:00.091,528] pipe: pipeline_connect: comp:4 0x40004 connect buffer 0 as sink [00:00:00.091,543] pipe: pipeline_connect: comp:4 0x60004 connect buffer 0 as source [00:00:00.092,170] ipc: ipc_cmd: rx : 0x45040006|0x20002 [00:00:00.092,283] ipc: buffer_new: buffer new size 0x300 id 4.0 flags 0x0 [00:00:00.092,308] pipe: pipeline_connect: comp:4 0x60004 connect buffer 0 as sink [00:00:00.092,321] pipe: pipeline_connect: comp:4 0x20002 connect buffer 0 as source [00:00:00.093,101] ipc: ipc_cmd: rx : 0x45020002|0x20003 [00:00:00.093,165] ipc: buffer_new: buffer new size 0x300 id 4.0 flags 0x0 [00:00:00.093,190] pipe: pipeline_connect: comp:4 0x20002 connect buffer 0 as sink [00:00:00.093,203] pipe: pipeline_connect: comp:5 0x30002 connect buffer 0 as source [00:00:00.094,026] ipc: ipc_cmd: rx : 0x45020003|0x50006 [00:00:00.094,086] ipc: buffer_new: buffer new size 0x300 id 5.0 flags 0x0 [00:00:00.094,110] pipe: pipeline_connect: comp:5 0x30002 connect buffer 0 as sink [00:00:00.094,130] pipe: pipeline_connect: comp:5 0x60005 connect buffer 0 as source [00:00:00.094,625] ipc: ipc_cmd: rx : 0x45050006|0x50004 [00:00:00.094,690] ipc: buffer_new: buffer new size 0x300 id 5.0 flags 0x0 [00:00:00.094,715] pipe: pipeline_connect: comp:5 0x60005 connect buffer 0 as sink [00:00:00.094,728] pipe: pipeline_connect: comp:5 0x40005 connect buffer 0 as source [00:00:00.097,576] ipc: ipc_cmd: rx : 0x13000003|0x1 [00:00:00.097,698] ipc: ipc_pipeline_complete(): no scheduling component specified, use comp 131074 [00:00:00.098,415] ipc: ipc_cmd: rx : 0x13000004|0x1 [00:00:00.098,508] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 1 [00:00:00.098,516] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 167952 [00:00:00.098,536] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 4 [00:00:00.098,545] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:00.098,566] dai_comp: dai_playback_params: comp:5 0x40005 dai_playback_params() dest_dev = 4 stream_id = 0 src_width = 4 dest_width = 4 [00:00:00.098,576] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 1 [00:00:00.098,585] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 167952 [00:00:00.098,593] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 4 [00:00:00.098,603] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:00.098,710] pipe: pipeline_trigger: pipe:5 0x0 pipe trigger cmd 7 [00:00:00.098,730] ll_schedule: zephyr_ll_task_schedule_common: task add 0xa0121a80 0x201b0U priority 0 flags 0x0 [00:00:00.098,763] ll_schedule: zephyr_domain_register: zephyr_domain_register domain->type 1 domain->clk 3 domain->ticks_per_ms 38400 period 1000 [00:00:00.098,871] mixer: mixin_prepare: comp:4 0x20002 mixin_prepare() [00:00:00.098,905] pipe: pipeline_trigger: pipe:4 0x0 pipe trigger cmd 7 [00:00:00.098,930] ll_schedule: zephyr_ll_task_schedule_common: task add 0xa0122340 0x201b0U priority 0 flags 0x0 [00:00:00.099,286] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 1 [00:00:00.099,295] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 167952 [00:00:00.099,303] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 4 [00:00:00.099,311] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:00.099,328] dai_intel_ssp: dai_ssp_pre_start: dai_ssp_pre_start [00:00:00.099,361] dai_intel_ssp: dai_ssp_start: dai_ssp_start [00:00:00.099,373] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 29000, reg 30, mask 100, value 100 [00:00:00.099,591] host_comp: host_get_copy_bytes_normal: comp:4 0x40004 no bytes to copy, available samples: 0, free_samples: 192 [00:00:01.097,375] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2876, max 9378, overruns 0 [00:00:01.104,390] ll_schedule: zephyr_domain_thread_fn: ll timer avg 3106, max 14346, overruns 0 [00:00:01.122,375] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2841, max 13414, overruns 0 [00:00:02.121,376] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2835, max 2908, overruns 0 [00:00:02.128,391] ll_schedule: zephyr_domain_thread_fn: ll timer avg 3067, max 4096, overruns 0 [00:00:02.146,373] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2872, max 3625, overruns 0 [00:00:03.145,376] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2834, max 2912, overruns 0 [00:00:03.152,388] ll_schedule: zephyr_domain_thread_fn: ll timer avg 3068, max 4104, overruns 0 [00:00:03.170,380] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2887, max 3619, overruns 0 [00:00:04.169,380] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2834, max 2921, overruns 0 [00:00:04.176,388] ll_schedule: zephyr_domain_thread_fn: ll timer avg 3067, max 4090, overruns 0 [00:00:04.194,373] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2888, max 3619, overruns 0 [00:00:05.193,376] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2834, max 2902, overruns 0 [00:00:05.200,390] ll_schedule: zephyr_domain_thread_fn: ll timer avg 3067, max 4086, overruns 0 [00:00:05.218,380] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2870, max 3792, overruns 0 [00:00:05.680,970] ipc: ipc_cmd: rx : 0x13000003|0x1 [00:00:05.681,030] pipe: pipeline_trigger: pipe:2 0x0 pipe trigger cmd 2 [00:00:05.681,056] pipe: pipeline_trigger: pipe:3 0x0 pipe trigger cmd 2 [00:00:05.681,301] dai_intel_ssp: dai_ssp_pause: dai_ssp_pause TX [00:00:05.681,316] ll_schedule: zephyr_ll_task_done: task complete 0xa011b740 0x201b0U [00:00:05.681,340] ll_schedule: zephyr_ll_task_done: num_tasks 2 total_num_tasks 6 [00:00:05.681,413] ll_schedule: zephyr_ll_task_done: task complete 0xa011c040 0x201b0U [00:00:05.681,425] ll_schedule: zephyr_ll_task_done: num_tasks 1 total_num_tasks 5 [00:00:05.681,441] ll_schedule: zephyr_domain_unregister: zephyr_domain_unregister domain->type 1 domain->clk 3 [00:00:05.682,183] ipc: ipc_cmd: rx : 0x13000002|0x1 [00:00:05.682,270] pipe: pipeline_trigger: pipe:3 0x0 pipe trigger cmd 0 [00:00:05.682,356] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 2a000, reg 30, mask 100, value 0 [00:00:05.682,365] dai_intel_ssp: dai_ssp_stop: dai_ssp_stopTX stop [00:00:05.682,378] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 2a000, reg 4, mask 300000, value 0 [00:00:05.682,390] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 2a000, reg 0, mask 80, value 0 [00:00:05.682,400] dai_intel_ssp: dai_ssp_stop: dai_ssp_stop SSE clear SSP2 [00:00:05.682,418] dma_intel_adsp_gpdma: intel_adsp_gpdma_power_off: intel_adsp_gpdma_power_off: dma dma@7d000 power off [00:00:05.682,525] pipe: pipeline_trigger: pipe:2 0x0 pipe trigger cmd 0 [00:00:05.682,570] copier: comp:2 0x40002 dai is not ready [00:00:05.683,545] ipc: ipc_cmd: rx : 0x13000003|0x1 [00:00:05.683,598] pipe: pipeline_trigger: pipe:4 0x0 pipe trigger cmd 2 [00:00:05.683,626] pipe: pipeline_trigger: pipe:5 0x0 pipe trigger cmd 2 [00:00:05.684,283] dai_intel_ssp: dai_ssp_pause: dai_ssp_pause TX [00:00:05.684,303] ll_schedule: zephyr_ll_task_done: task complete 0xa0121a80 0x201b0U [00:00:05.684,313] ll_schedule: zephyr_ll_task_done: num_tasks 2 total_num_tasks 4 [00:00:05.684,375] ll_schedule: zephyr_ll_task_done: task complete 0xa0122340 0x201b0U [00:00:05.684,386] ll_schedule: zephyr_ll_task_done: num_tasks 1 total_num_tasks 3 [00:00:05.684,401] ll_schedule: zephyr_domain_unregister: zephyr_domain_unregister domain->type 1 domain->clk 3 [00:00:05.684,998] ipc: ipc_cmd: rx : 0x13000003|0x1 [00:00:05.685,013] pipe: pipeline_trigger: pipe:0 0x0 pipe trigger cmd 2 [00:00:05.685,036] pipe: pipeline_trigger: pipe:1 0x0 pipe trigger cmd 2 [00:00:05.685,313] dai_intel_ssp: dai_ssp_pause: dai_ssp_pause TX [00:00:05.685,328] ll_schedule: zephyr_ll_task_done: task complete 0xa011d100 0x201b0U [00:00:05.685,338] ll_schedule: zephyr_ll_task_done: num_tasks 2 total_num_tasks 2 [00:00:05.685,385] ll_schedule: zephyr_ll_task_done: task complete 0xa011d9c0 0x201b0U [00:00:05.685,396] ll_schedule: zephyr_ll_task_done: num_tasks 1 total_num_tasks 1 [00:00:05.685,425] ll_schedule: zephyr_domain_unregister: zephyr_domain_unregister domain->type 1 domain->clk 3 [00:00:05.687,181] ipc: ipc_cmd: rx : 0x46010002|0x10003 [00:00:05.687,983] ipc: ipc_cmd: rx : 0x12020000|0x0 [00:00:05.688,053] dma: dma_put: dma_put(), dma = 0x400f93d0, sref = 2 [00:00:05.688,846] ipc: ipc_cmd: rx : 0x12030000|0x0 [00:00:05.689,026] dma: dma_put: dma_put(), dma = 0x400f9330, sref = 0 [00:00:05.689,041] dai_intel_ssp: dai_ssp_pm_runtime_dis_ssp_power: dai_ssp_pm_runtime_dis_ssp_power index 2 [00:00:05.689,195] dai_intel_ssp: dai_ssp_poll_for_register_delay poll timeout reg 165892 mask 1024 val 1024 us 125 [00:00:05.689,203] dai_intel_ssp: dai_ssp_pm_runtime_dis_ssp_power warning: timeout [00:00:05.689,215] dai_intel_ssp: dai_ssp_pm_runtime_dis_ssp_power: dai_ssp_pm_runtime_dis_ssp_power I2SLCTL [00:00:05.690,011] ipc: ipc_cmd: rx : 0x47000000|0x0 [00:00:05.691,053] ipc: ipc_cmd: rx : 0x13000002|0x1 [00:00:05.691,115] pipe: pipeline_trigger: pipe:5 0x0 pipe trigger cmd 0 [00:00:05.691,181] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 29000, reg 30, mask 100, value 0 [00:00:05.691,190] dai_intel_ssp: dai_ssp_stop: dai_ssp_stopTX stop [00:00:05.691,201] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 29000, reg 4, mask 300000, value 0 [00:00:05.691,225] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 29000, reg 0, mask 80, value 0 [00:00:05.691,240] dai_intel_ssp: dai_ssp_stop: dai_ssp_stop SSE clear SSP1 [00:00:05.691,353] pipe: pipeline_trigger: pipe:4 0x0 pipe trigger cmd 0 [00:00:05.691,391] copier: comp:4 0x40004 dai is not ready [00:00:05.692,183] ipc: ipc_cmd: rx : 0x46020002|0x20003 [00:00:05.692,750] ipc: ipc_cmd: rx : 0x12040000|0x0 [00:00:05.692,815] dma: dma_put: dma_put(), dma = 0x400f93d0, sref = 1 [00:00:05.693,608] ipc: ipc_cmd: rx : 0x12050000|0x0 [00:00:05.693,798] dma: dma_put: dma_put(), dma = 0x400f92e0, sref = 1 [00:00:05.693,813] dai_intel_ssp: dai_ssp_pm_runtime_dis_ssp_power: dai_ssp_pm_runtime_dis_ssp_power index 1 [00:00:05.693,950] dai_intel_ssp: dai_ssp_poll_for_register_delay poll timeout reg 165892 mask 512 val 512 us 125 [00:00:05.693,960] dai_intel_ssp: dai_ssp_pm_runtime_dis_ssp_power warning: timeout [00:00:05.693,981] dai_intel_ssp: dai_ssp_pm_runtime_dis_ssp_power: dai_ssp_pm_runtime_dis_ssp_power I2SLCTL [00:00:05.694,783] ipc: ipc_cmd: rx : 0x47000000|0x0 [00:00:05.695,723] ipc: ipc_cmd: rx : 0x13000002|0x1 [00:00:05.695,750] pipe: pipeline_trigger: pipe:1 0x0 pipe trigger cmd 0 [00:00:05.695,816] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 28000, reg 30, mask 100, value 0 [00:00:05.695,825] dai_intel_ssp: dai_ssp_stop: dai_ssp_stopTX stop [00:00:05.695,836] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 28000, reg 4, mask 300000, value 0 [00:00:05.695,860] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 28000, reg 0, mask 80, value 0 [00:00:05.695,870] dai_intel_ssp: dai_ssp_stop: dai_ssp_stop SSE clear SSP0 [00:00:05.695,886] dma_intel_adsp_gpdma: intel_adsp_gpdma_power_off: intel_adsp_gpdma_power_off: dma dma@7c000 power off [00:00:05.695,986] pipe: pipeline_trigger: pipe:0 0x0 pipe trigger cmd 0 [00:00:05.696,020] copier: comp:0 0x40000 dai is not ready [00:00:05.696,716] ipc: ipc_cmd: rx : 0x46000002|0x3 [00:00:05.697,545] ipc: ipc_cmd: rx : 0x12000000|0x0 [00:00:05.697,568] dma: dma_put: dma_put(), dma = 0x400f93d0, sref = 0 [00:00:05.698,453] ipc: ipc_cmd: rx : 0x12010000|0x0 [00:00:05.698,598] dma: dma_put: dma_put(), dma = 0x400f92e0, sref = 0 [00:00:05.698,613] dai_intel_ssp: dai_ssp_pm_runtime_dis_ssp_power: dai_ssp_pm_runtime_dis_ssp_power index 0 [00:00:05.698,751] dai_intel_ssp: dai_ssp_poll_for_register_delay poll timeout reg 165892 mask 256 val 256 us 125 [00:00:05.698,760] dai_intel_ssp: dai_ssp_pm_runtime_dis_ssp_power warning: timeout [00:00:05.698,783] dai_intel_ssp: dai_ssp_pm_runtime_dis_ssp_power: dai_ssp_pm_runtime_dis_ssp_power I2SLCTL [00:00:07.157,498] ipc: ipc_cmd: rx : 0x11000007|0x0 [00:00:07.157,516] pipe: pipeline_new: pipeline new pipe_id 0 priority 0 [00:00:07.157,948] ipc: ipc_cmd: rx : 0x40000004|0x15 [00:00:07.157,995] dma: dma_get: dma_get() ID 0 sref = 1 busy channels 0 [00:00:07.158,743] ipc: ipc_cmd: rx : 0x40000006|0x10 [00:00:07.159,520] ipc: ipc_cmd: rx : 0x44000006|0x30000018 [00:00:07.160,021] ipc: ipc_cmd: rx : 0x40000002|0xa [00:00:07.160,498] ipc: ipc_cmd: rx : 0x11010006|0x0 [00:00:07.160,513] pipe: pipeline_new: pipeline new pipe_id 1 priority 0 [00:00:07.160,853] ipc: ipc_cmd: rx : 0x40000003|0x1000a [00:00:07.161,291] ipc: ipc_cmd: rx : 0x40010006|0x10010 [00:00:07.161,765] ipc: ipc_cmd: rx : 0x44010006|0x30000018 [00:00:07.162,216] ipc: ipc_cmd: rx : 0x40010004|0x1002f [00:00:07.162,285] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power: dai_ssp_pm_runtime_en_ssp_power en_ssp_power index 0 [00:00:07.162,423] dai_intel_ssp: dai_ssp_poll_for_register_delay poll timeout reg 165892 mask 256 val 0 us 125 [00:00:07.162,431] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power warning: timeout [00:00:07.162,440] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power: dai_ssp_pm_runtime_en_ssp_power I2SLCTL [00:00:07.162,458] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 28000, reg 8, mask 80, value 80 [00:00:07.162,483] dma: dma_get: dma_get() ID 0 sref = 1 busy channels 0 [00:00:07.162,498] ipc: dai_config: comp:1 0x40001 dai_config() dai type = 1 index = 0 dd 0x40115200 [00:00:07.162,518] dai_intel_ssp: dai_ssp_parse_aux_data: dai_ssp_parse_aux_data link clock_source 1 [00:00:07.162,536] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config sscr0 = 0xc1d0077f, sscr1 = 0xd0700004, ssto = 0x00000000, sspsp = 0x2200000 [00:00:07.162,550] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config sscr2 = 0x00004002, sspsp2 = 0x00000000, sscr3 = 0x07070000 [00:00:07.162,563] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config ssioc = 0x00000020, ssrsa = 0x00000003, sstsa = 0x00000003 [00:00:07.162,576] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 28000, reg 4, mask 300000, value 300000 [00:00:07.162,588] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 28000, reg 0, mask 80, value 80 [00:00:07.163,073] ipc: ipc_cmd: rx : 0x45000004|0x6 [00:00:07.163,090] ipc: buffer_new: buffer new size 0x300 id 0.0 flags 0x0 [00:00:07.163,115] pipe: pipeline_connect: comp:0 0x40000 connect buffer 0 as sink [00:00:07.163,128] pipe: pipeline_connect: comp:0 0x60000 connect buffer 0 as source [00:00:07.163,620] ipc: ipc_cmd: rx : 0x45000006|0x2 [00:00:07.163,636] ipc: buffer_new: buffer new size 0x300 id 0.0 flags 0x0 [00:00:07.163,660] pipe: pipeline_connect: comp:0 0x60000 connect buffer 0 as sink [00:00:07.163,675] pipe: pipeline_connect: comp:0 0x20000 connect buffer 0 as source [00:00:07.164,081] ipc: ipc_cmd: rx : 0x45000002|0x3 [00:00:07.164,098] ipc: buffer_new: buffer new size 0x300 id 0.0 flags 0x0 [00:00:07.164,123] pipe: pipeline_connect: comp:0 0x20000 connect buffer 0 as sink [00:00:07.164,136] pipe: pipeline_connect: comp:1 0x30000 connect buffer 0 as source [00:00:07.164,771] ipc: ipc_cmd: rx : 0x45000003|0x10006 [00:00:07.164,790] ipc: buffer_new: buffer new size 0x300 id 1.0 flags 0x0 [00:00:07.164,813] pipe: pipeline_connect: comp:1 0x30000 connect buffer 0 as sink [00:00:07.164,826] pipe: pipeline_connect: comp:1 0x60001 connect buffer 0 as source [00:00:07.165,245] ipc: ipc_cmd: rx : 0x45010006|0x10004 [00:00:07.165,261] ipc: buffer_new: buffer new size 0x300 id 1.0 flags 0x0 [00:00:07.165,286] pipe: pipeline_connect: comp:1 0x60001 connect buffer 0 as sink [00:00:07.165,300] pipe: pipeline_connect: comp:1 0x40001 connect buffer 0 as source [00:00:07.167,715] ipc: ipc_cmd: rx : 0x13000003|0x1 [00:00:07.167,761] ipc: ipc_pipeline_complete(): no scheduling component specified, use comp 131072 [00:00:07.168,326] ipc: ipc_cmd: rx : 0x13000004|0x1 [00:00:07.168,381] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 0 [00:00:07.168,390] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 163856 [00:00:07.168,398] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 2 [00:00:07.168,406] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:07.168,426] dai_comp: dai_playback_params: comp:1 0x40001 dai_playback_params() dest_dev = 2 stream_id = 0 src_width = 4 dest_width = 4 [00:00:07.168,438] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 0 [00:00:07.168,445] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 163856 [00:00:07.168,455] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 2 [00:00:07.168,463] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:07.168,566] pipe: pipeline_trigger: pipe:1 0x0 pipe trigger cmd 7 [00:00:07.168,588] ll_schedule: zephyr_ll_task_schedule_common: task add 0xa0116f00 0x201b0U priority 0 flags 0x0 [00:00:07.168,631] ll_schedule: zephyr_domain_register: zephyr_domain_register domain->type 1 domain->clk 3 domain->ticks_per_ms 38400 period 1000 [00:00:07.168,690] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 0 [00:00:07.168,698] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 163856 [00:00:07.168,706] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 2 [00:00:07.168,716] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:07.168,728] dai_intel_ssp: dai_ssp_pre_start: dai_ssp_pre_start [00:00:07.168,760] dma_intel_adsp_gpdma: intel_adsp_gpdma_power_on: intel_adsp_gpdma_power_on: dma dma@7c000 initialized [00:00:07.168,791] dai_intel_ssp: dai_ssp_start: dai_ssp_start [00:00:07.168,803] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 28000, reg 30, mask 100, value 100 [00:00:07.169,023] mixer: mixin_prepare: comp:0 0x20000 mixin_prepare() [00:00:07.169,056] pipe: pipeline_trigger: pipe:0 0x0 pipe trigger cmd 7 [00:00:07.169,080] ll_schedule: zephyr_ll_task_schedule_common: task add 0xa01181c0 0x201b0U priority 0 flags 0x0 [00:00:07.169,856] host_comp: host_get_copy_bytes_normal: comp:0 0x40000 no bytes to copy, available samples: 0, free_samples: 192 [00:00:07.170,551] ipc: ipc_cmd: rx : 0x47000000|0x0 [00:00:07.171,321] ipc: ipc_cmd: rx : 0x11020007|0x200000 [00:00:07.171,371] pipe: pipeline_new: pipeline new pipe_id 2 priority 0 [00:00:07.172,121] ipc: ipc_cmd: rx : 0x40020004|0x2020015 [00:00:07.172,196] dma: dma_get: dma_get() ID 0 sref = 2 busy channels 0 [00:00:07.172,571] ipc: ipc_cmd: rx : 0x40020006|0x2020010 [00:00:07.173,373] ipc: ipc_cmd: rx : 0x44020006|0x30000018 [00:00:07.174,618] ipc: ipc_cmd: rx : 0x40010002|0x202000a [00:00:07.175,250] ipc: ipc_cmd: rx : 0x11030006|0x200000 [00:00:07.175,298] pipe: pipeline_new: pipeline new pipe_id 3 priority 0 [00:00:07.175,856] ipc: ipc_cmd: rx : 0x40010003|0x203000a [00:00:07.176,378] ipc: ipc_cmd: rx : 0x40030006|0x2030010 [00:00:07.177,040] ipc: ipc_cmd: rx : 0x44030006|0x30000018 [00:00:07.177,591] ipc: ipc_cmd: rx : 0x40030004|0x203002f [00:00:07.177,726] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power: dai_ssp_pm_runtime_en_ssp_power en_ssp_power index 2 [00:00:07.177,865] dai_intel_ssp: dai_ssp_poll_for_register_delay poll timeout reg 165892 mask 1024 val 0 us 125 [00:00:07.177,875] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power warning: timeout [00:00:07.177,888] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power: dai_ssp_pm_runtime_en_ssp_power I2SLCTL [00:00:07.177,905] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 2a000, reg 8, mask 80, value 80 [00:00:07.177,930] dma: dma_get: dma_get() ID 0 sref = 1 busy channels 0 [00:00:07.177,946] ipc: dai_config: comp:3 0x40003 dai_config() dai type = 1 index = 2 dd 0x4011a1c0 [00:00:07.177,966] dai_intel_ssp: dai_ssp_parse_aux_data: dai_ssp_parse_aux_data link clock_source 1 [00:00:07.177,985] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config sscr0 = 0xc1d0077f, sscr1 = 0xd0700004, ssto = 0x00000000, sspsp = 0x2200000 [00:00:07.177,998] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config sscr2 = 0x00004002, sspsp2 = 0x00000000, sscr3 = 0x07070000 [00:00:07.178,011] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config ssioc = 0x00000020, ssrsa = 0x00000003, sstsa = 0x00000003 [00:00:07.178,025] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 2a000, reg 4, mask 300000, value 300000 [00:00:07.178,036] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 2a000, reg 0, mask 80, value 80 [00:00:07.180,100] ipc: ipc_cmd: rx : 0x45020004|0x20006 [00:00:07.180,160] ipc: buffer_new: buffer new size 0x300 id 2.0 flags 0x0 [00:00:07.180,185] pipe: pipeline_connect: comp:2 0x40002 connect buffer 0 as sink [00:00:07.180,200] pipe: pipeline_connect: comp:2 0x60002 connect buffer 0 as source [00:00:07.180,828] ipc: ipc_cmd: rx : 0x45020006|0x10002 [00:00:07.180,883] ipc: buffer_new: buffer new size 0x300 id 2.0 flags 0x0 [00:00:07.180,908] pipe: pipeline_connect: comp:2 0x60002 connect buffer 0 as sink [00:00:07.180,925] pipe: pipeline_connect: comp:2 0x20001 connect buffer 0 as source [00:00:07.181,585] ipc: ipc_cmd: rx : 0x45010002|0x10003 [00:00:07.181,680] ipc: buffer_new: buffer new size 0x300 id 2.0 flags 0x0 [00:00:07.181,705] pipe: pipeline_connect: comp:2 0x20001 connect buffer 0 as sink [00:00:07.181,718] pipe: pipeline_connect: comp:3 0x30001 connect buffer 0 as source [00:00:07.182,275] ipc: ipc_cmd: rx : 0x45010003|0x30006 [00:00:07.182,333] ipc: buffer_new: buffer new size 0x300 id 3.0 flags 0x0 [00:00:07.182,358] pipe: pipeline_connect: comp:3 0x30001 connect buffer 0 as sink [00:00:07.182,373] pipe: pipeline_connect: comp:3 0x60003 connect buffer 0 as source [00:00:07.183,146] ipc: ipc_cmd: rx : 0x45030006|0x30004 [00:00:07.183,205] ipc: buffer_new: buffer new size 0x300 id 3.0 flags 0x0 [00:00:07.183,230] pipe: pipeline_connect: comp:3 0x60003 connect buffer 0 as sink [00:00:07.183,245] pipe: pipeline_connect: comp:3 0x40003 connect buffer 0 as source [00:00:07.183,965] ipc: ipc_cmd: rx : 0x13000003|0x1 [00:00:07.184,070] ipc: ipc_pipeline_complete(): no scheduling component specified, use comp 131073 [00:00:07.184,848] ipc: ipc_cmd: rx : 0x13000004|0x1 [00:00:07.184,941] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 2 [00:00:07.184,950] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 172048 [00:00:07.184,963] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 6 [00:00:07.184,973] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:07.184,993] dai_comp: dai_playback_params: comp:3 0x40003 dai_playback_params() dest_dev = 6 stream_id = 0 src_width = 4 dest_width = 4 [00:00:07.185,005] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 2 [00:00:07.185,013] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 172048 [00:00:07.185,021] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 6 [00:00:07.185,030] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:07.185,166] pipe: pipeline_trigger: pipe:3 0x0 pipe trigger cmd 7 [00:00:07.185,188] ll_schedule: zephyr_ll_task_schedule_common: task add 0xa011d000 0x201b0U priority 0 flags 0x0 [00:00:07.185,226] ll_schedule: zephyr_domain_register: zephyr_domain_register domain->type 1 domain->clk 3 domain->ticks_per_ms 38400 period 1000 [00:00:07.185,336] mixer: mixin_prepare: comp:2 0x20001 mixin_prepare() [00:00:07.185,371] pipe: pipeline_trigger: pipe:2 0x0 pipe trigger cmd 7 [00:00:07.185,395] ll_schedule: zephyr_ll_task_schedule_common: task add 0xa011d8c0 0x201b0U priority 0 flags 0x0 [00:00:07.185,696] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 2 [00:00:07.185,705] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 172048 [00:00:07.185,713] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 6 [00:00:07.185,723] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:07.185,735] dai_intel_ssp: dai_ssp_pre_start: dai_ssp_pre_start [00:00:07.185,771] dma_intel_adsp_gpdma: intel_adsp_gpdma_power_on: intel_adsp_gpdma_power_on: dma dma@7d000 initialized [00:00:07.185,805] dai_intel_ssp: dai_ssp_start: dai_ssp_start [00:00:07.185,816] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 2a000, reg 30, mask 100, value 100 [00:00:07.186,028] host_comp: host_get_copy_bytes_normal: comp:2 0x40002 no bytes to copy, available samples: 0, free_samples: 192 [00:00:07.186,850] ipc: ipc_cmd: rx : 0x47000000|0x0 [00:00:07.187,875] ipc: ipc_cmd: rx : 0x11040007|0x100000 [00:00:07.187,926] pipe: pipeline_new: pipeline new pipe_id 4 priority 0 [00:00:07.188,571] ipc: ipc_cmd: rx : 0x40040004|0x1040015 [00:00:07.188,706] dma: dma_get: dma_get() ID 0 sref = 3 busy channels 0 [00:00:07.189,206] ipc: ipc_cmd: rx : 0x40040006|0x1040010 [00:00:07.191,153] ipc: ipc_cmd: rx : 0x44040006|0x30000018 [00:00:07.191,818] ipc: ipc_cmd: rx : 0x40020002|0x104000a [00:00:07.192,543] ipc: ipc_cmd: rx : 0x11050006|0x100000 [00:00:07.192,593] pipe: pipeline_new: pipeline new pipe_id 5 priority 0 [00:00:07.193,036] ipc: ipc_cmd: rx : 0x40020003|0x105000a [00:00:07.193,823] ipc: ipc_cmd: rx : 0x40050006|0x1050010 [00:00:07.194,518] ipc: ipc_cmd: rx : 0x44050006|0x30000018 [00:00:07.195,023] ipc: ipc_cmd: rx : 0x40050004|0x105002f [00:00:07.195,126] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power: dai_ssp_pm_runtime_en_ssp_power en_ssp_power index 1 [00:00:07.195,266] dai_intel_ssp: dai_ssp_poll_for_register_delay poll timeout reg 165892 mask 512 val 0 us 125 [00:00:07.195,275] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power warning: timeout [00:00:07.195,296] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power: dai_ssp_pm_runtime_en_ssp_power I2SLCTL [00:00:07.195,310] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 29000, reg 8, mask 80, value 80 [00:00:07.195,328] dma: dma_get: dma_get() ID 0 sref = 2 busy channels 0 [00:00:07.195,345] ipc: dai_config: comp:5 0x40005 dai_config() dai type = 1 index = 1 dd 0x4011f900 [00:00:07.195,365] dai_intel_ssp: dai_ssp_parse_aux_data: dai_ssp_parse_aux_data link clock_source 1 [00:00:07.195,381] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config sscr0 = 0xc1d0077f, sscr1 = 0xd0700004, ssto = 0x00000000, sspsp = 0x2200000 [00:00:07.195,396] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config sscr2 = 0x00004002, sspsp2 = 0x00000000, sscr3 = 0x07070000 [00:00:07.195,410] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config ssioc = 0x00000020, ssrsa = 0x00000003, sstsa = 0x00000003 [00:00:07.195,423] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 29000, reg 4, mask 300000, value 300000 [00:00:07.195,435] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 29000, reg 0, mask 80, value 80 [00:00:07.196,286] ipc: ipc_cmd: rx : 0x45040004|0x40006 [00:00:07.196,346] ipc: buffer_new: buffer new size 0x300 id 4.0 flags 0x0 [00:00:07.196,371] pipe: pipeline_connect: comp:4 0x40004 connect buffer 0 as sink [00:00:07.196,386] pipe: pipeline_connect: comp:4 0x60004 connect buffer 0 as source [00:00:07.197,088] ipc: ipc_cmd: rx : 0x45040006|0x20002 [00:00:07.197,148] ipc: buffer_new: buffer new size 0x300 id 4.0 flags 0x0 [00:00:07.197,171] pipe: pipeline_connect: comp:4 0x60004 connect buffer 0 as sink [00:00:07.197,186] pipe: pipeline_connect: comp:4 0x20002 connect buffer 0 as source [00:00:07.197,905] ipc: ipc_cmd: rx : 0x45020002|0x20003 [00:00:07.197,965] ipc: buffer_new: buffer new size 0x300 id 4.0 flags 0x0 [00:00:07.197,990] pipe: pipeline_connect: comp:4 0x20002 connect buffer 0 as sink [00:00:07.198,005] pipe: pipeline_connect: comp:5 0x30002 connect buffer 0 as source [00:00:07.198,886] ipc: ipc_cmd: rx : 0x45020003|0x50006 [00:00:07.198,948] ipc: buffer_new: buffer new size 0x300 id 5.0 flags 0x0 [00:00:07.198,971] pipe: pipeline_connect: comp:5 0x30002 connect buffer 0 as sink [00:00:07.198,986] pipe: pipeline_connect: comp:5 0x60005 connect buffer 0 as source [00:00:07.199,781] ipc: ipc_cmd: rx : 0x45050006|0x50004 [00:00:07.199,851] ipc: buffer_new: buffer new size 0x300 id 5.0 flags 0x0 [00:00:07.199,875] pipe: pipeline_connect: comp:5 0x60005 connect buffer 0 as sink [00:00:07.199,891] pipe: pipeline_connect: comp:5 0x40005 connect buffer 0 as source [00:00:07.201,283] ipc: ipc_cmd: rx : 0x13000003|0x1 [00:00:07.201,405] ipc: ipc_pipeline_complete(): no scheduling component specified, use comp 131074 [00:00:07.202,116] ipc: ipc_cmd: rx : 0x13000004|0x1 [00:00:07.202,218] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 1 [00:00:07.202,226] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 167952 [00:00:07.202,236] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 4 [00:00:07.202,245] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:07.202,273] dai_comp: dai_playback_params: comp:5 0x40005 dai_playback_params() dest_dev = 4 stream_id = 0 src_width = 4 dest_width = 4 [00:00:07.202,290] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 1 [00:00:07.202,296] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 167952 [00:00:07.202,306] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 4 [00:00:07.202,315] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:07.202,421] pipe: pipeline_trigger: pipe:5 0x0 pipe trigger cmd 7 [00:00:07.202,443] ll_schedule: zephyr_ll_task_schedule_common: task add 0xa0121a80 0x201b0U priority 0 flags 0x0 [00:00:07.202,475] ll_schedule: zephyr_domain_register: zephyr_domain_register domain->type 1 domain->clk 3 domain->ticks_per_ms 38400 period 1000 [00:00:07.202,585] mixer: mixin_prepare: comp:4 0x20002 mixin_prepare() [00:00:07.202,618] pipe: pipeline_trigger: pipe:4 0x0 pipe trigger cmd 7 [00:00:07.202,715] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 1 [00:00:07.202,723] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 167952 [00:00:07.202,733] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 4 [00:00:07.202,741] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:07.202,753] dai_intel_ssp: dai_ssp_pre_start: dai_ssp_pre_start [00:00:07.202,786] dai_intel_ssp: dai_ssp_start: dai_ssp_start [00:00:07.202,798] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 29000, reg 30, mask 100, value 100 [00:00:07.202,928] ll_schedule: zephyr_ll_task_schedule_common: task add 0xa0122340 0x201b0U priority 0 flags 0x0 [00:00:07.203,855] host_comp: host_get_copy_bytes_normal: comp:4 0x40004 no bytes to copy, available samples: 0, free_samples: 192 [00:00:08.191,803] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2965, max 9094, overruns 0 [00:00:08.208,790] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2838, max 14314, overruns 0 [00:00:08.225,775] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2903, max 7841, overruns 0 [00:00:09.215,800] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2926, max 3004, overruns 0 [00:00:09.232,790] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2800, max 2894, overruns 0 [00:00:09.249,776] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2889, max 3599, overruns 0 [00:00:10.239,801] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2926, max 3390, overruns 0 [00:00:10.256,788] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2800, max 2892, overruns 0 [00:00:10.273,793] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2873, max 3585, overruns 0 [00:00:11.263,803] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2927, max 3558, overruns 0 [00:00:11.280,790] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2800, max 2878, overruns 0 [00:00:11.297,776] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2871, max 3592, overruns 0 [00:00:12.287,803] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2924, max 3000, overruns 0 [00:00:12.304,795] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2800, max 2890, overruns 0 [00:00:12.321,798] ll_schedule: zephyr_domain_thread_fn: ll timer avg 2890, max 3551, overruns 0 [00:00:12.876,945] ipc: ipc_cmd: rx : 0x13000003|0x1 [00:00:12.877,006] pipe: pipeline_trigger: pipe:2 0x0 pipe trigger cmd 2 [00:00:12.877,033] pipe: pipeline_trigger: pipe:3 0x0 pipe trigger cmd 2 [00:00:12.877,735] dai_intel_ssp: dai_ssp_pause: dai_ssp_pause TX [00:00:12.877,748] ll_schedule: zephyr_ll_task_done: task complete 0xa011d000 0x201b0U [00:00:12.877,771] ll_schedule: zephyr_ll_task_done: num_tasks 2 total_num_tasks 6 [00:00:12.877,823] ll_schedule: zephyr_ll_task_done: task complete 0xa011d8c0 0x201b0U [00:00:12.877,836] ll_schedule: zephyr_ll_task_done: num_tasks 1 total_num_tasks 5 [00:00:12.877,853] ll_schedule: zephyr_domain_unregister: zephyr_domain_unregister domain->type 1 domain->clk 3 [00:00:12.878,595] ipc: ipc_cmd: rx : 0x13000003|0x1 [00:00:12.878,798] pipe: pipeline_trigger: pipe:4 0x0 pipe trigger cmd 2 [00:00:12.878,826] pipe: pipeline_trigger: pipe:5 0x0 pipe trigger cmd 2 [00:00:12.879,703] dai_intel_ssp: dai_ssp_pause: dai_ssp_pause TX [00:00:12.879,725] ll_schedule: zephyr_ll_task_done: task complete 0xa0121a80 0x201b0U [00:00:12.879,736] ll_schedule: zephyr_ll_task_done: num_tasks 2 total_num_tasks 4 [00:00:12.879,788] ll_schedule: zephyr_ll_task_done: task complete 0xa0122340 0x201b0U [00:00:12.879,800] ll_schedule: zephyr_ll_task_done: num_tasks 1 total_num_tasks 3 [00:00:12.879,841] ll_schedule: zephyr_domain_unregister: zephyr_domain_unregister domain->type 1 domain->clk 3 [00:00:12.880,620] ipc: ipc_cmd: rx : 0x13000003|0x1 [00:00:12.880,776] pipe: pipeline_trigger: pipe:0 0x0 pipe trigger cmd 2 [00:00:12.880,801] pipe: pipeline_trigger: pipe:1 0x0 pipe trigger cmd 2 [00:00:12.881,693] dai_intel_ssp: dai_ssp_pause: dai_ssp_pause TX [00:00:12.881,715] ll_schedule: zephyr_ll_task_done: task complete 0xa0116f00 0x201b0U [00:00:12.881,725] ll_schedule: zephyr_ll_task_done: num_tasks 2 total_num_tasks 2 [00:00:12.881,771] ll_schedule: zephyr_ll_task_done: task complete 0xa01181c0 0x201b0U [00:00:12.881,783] ll_schedule: zephyr_ll_task_done: num_tasks 1 total_num_tasks 1 [00:00:12.881,815] ll_schedule: zephyr_domain_unregister: zephyr_domain_unregister domain->type 1 domain->clk 3 [00:00:12.882,746] ipc: ipc_cmd: rx : 0x13000002|0x1 [00:00:12.882,841] pipe: pipeline_trigger: pipe:3 0x0 pipe trigger cmd 0 [00:00:12.882,910] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 2a000, reg 30, mask 100, value 0 [00:00:12.882,918] dai_intel_ssp: dai_ssp_stop: dai_ssp_stopTX stop [00:00:12.882,930] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 2a000, reg 4, mask 300000, value 0 [00:00:12.882,943] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 2a000, reg 0, mask 80, value 0 [00:00:12.882,958] dai_intel_ssp: dai_ssp_stop: dai_ssp_stop SSE clear SSP2 [00:00:12.882,975] dma_intel_adsp_gpdma: intel_adsp_gpdma_power_off: intel_adsp_gpdma_power_off: dma dma@7d000 power off [00:00:12.883,081] pipe: pipeline_trigger: pipe:2 0x0 pipe trigger cmd 0 [00:00:12.883,126] copier: comp:2 0x40002 dai is not ready [00:00:12.883,575] ipc: ipc_cmd: rx : 0x46010002|0x10003 [00:00:12.884,335] ipc: ipc_cmd: rx : 0x12020000|0x0 [00:00:12.884,396] dma: dma_put: dma_put(), dma = 0x400f93d0, sref = 2 [00:00:12.885,331] ipc: ipc_cmd: rx : 0x12030000|0x0 [00:00:12.885,523] dma: dma_put: dma_put(), dma = 0x400f9330, sref = 0 [00:00:12.885,538] dai_intel_ssp: dai_ssp_pm_runtime_dis_ssp_power: dai_ssp_pm_runtime_dis_ssp_power index 2 [00:00:12.885,676] dai_intel_ssp: dai_ssp_poll_for_register_delay poll timeout reg 165892 mask 1024 val 1024 us 125 [00:00:12.885,685] dai_intel_ssp: dai_ssp_pm_runtime_dis_ssp_power warning: timeout [00:00:12.885,708] dai_intel_ssp: dai_ssp_pm_runtime_dis_ssp_power: dai_ssp_pm_runtime_dis_ssp_power I2SLCTL [00:00:12.886,388] ipc: ipc_cmd: rx : 0x47000000|0x0 [00:00:12.886,998] ipc: ipc_cmd: rx : 0x13000002|0x1 [00:00:12.887,060] pipe: pipeline_trigger: pipe:5 0x0 pipe trigger cmd 0 [00:00:12.887,128] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 29000, reg 30, mask 100, value 0 [00:00:12.887,136] dai_intel_ssp: dai_ssp_stop: dai_ssp_stopTX stop [00:00:12.887,148] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 29000, reg 4, mask 300000, value 0 [00:00:12.887,171] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 29000, reg 0, mask 80, value 0 [00:00:12.887,185] dai_intel_ssp: dai_ssp_stop: dai_ssp_stop SSE clear SSP1 [00:00:12.887,300] pipe: pipeline_trigger: pipe:4 0x0 pipe trigger cmd 0 [00:00:12.887,338] copier: comp:4 0x40004 dai is not ready [00:00:12.888,116] ipc: ipc_cmd: rx : 0x46020002|0x20003 [00:00:12.889,425] ipc: ipc_cmd: rx : 0x12040000|0x0 [00:00:12.889,491] dma: dma_put: dma_put(), dma = 0x400f93d0, sref = 1 [00:00:12.890,421] ipc: ipc_cmd: rx : 0x12050000|0x0 [00:00:12.890,593] dma: dma_put: dma_put(), dma = 0x400f92e0, sref = 1 [00:00:12.890,608] dai_intel_ssp: dai_ssp_pm_runtime_dis_ssp_power: dai_ssp_pm_runtime_dis_ssp_power index 1 [00:00:12.890,760] dai_intel_ssp: dai_ssp_poll_for_register_delay poll timeout reg 165892 mask 512 val 512 us 125 [00:00:12.890,770] dai_intel_ssp: dai_ssp_pm_runtime_dis_ssp_power warning: timeout [00:00:12.890,781] dai_intel_ssp: dai_ssp_pm_runtime_dis_ssp_power: dai_ssp_pm_runtime_dis_ssp_power I2SLCTL [00:00:12.891,371] ipc: ipc_cmd: rx : 0x47000000|0x0 [00:00:12.892,200] ipc: ipc_cmd: rx : 0x13000002|0x1 [00:00:12.892,225] pipe: pipeline_trigger: pipe:1 0x0 pipe trigger cmd 0 [00:00:12.892,291] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 28000, reg 30, mask 100, value 0 [00:00:12.892,300] dai_intel_ssp: dai_ssp_stop: dai_ssp_stopTX stop [00:00:12.892,313] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 28000, reg 4, mask 300000, value 0 [00:00:12.892,336] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 28000, reg 0, mask 80, value 0 [00:00:12.892,345] dai_intel_ssp: dai_ssp_stop: dai_ssp_stop SSE clear SSP0 [00:00:12.892,361] dma_intel_adsp_gpdma: intel_adsp_gpdma_power_off: intel_adsp_gpdma_power_off: dma dma@7c000 power off [00:00:12.892,461] pipe: pipeline_trigger: pipe:0 0x0 pipe trigger cmd 0 [00:00:12.892,495] copier: comp:0 0x40000 dai is not ready [00:00:12.893,346] ipc: ipc_cmd: rx : 0x46000002|0x3 [00:00:12.893,878] ipc: ipc_cmd: rx : 0x12000000|0x0 [00:00:12.893,901] dma: dma_put: dma_put(), dma = 0x400f93d0, sref = 0 [00:00:12.894,638] ipc: ipc_cmd: rx : 0x12010000|0x0 [00:00:12.894,773] dma: dma_put: dma_put(), dma = 0x400f92e0, sref = 0 [00:00:12.894,788] dai_intel_ssp: dai_ssp_pm_runtime_dis_ssp_power: dai_ssp_pm_runtime_dis_ssp_power index 0 [00:00:12.894,926] dai_intel_ssp: dai_ssp_poll_for_register_delay poll timeout reg 165892 mask 256 val 256 us 125 [00:00:12.894,938] dai_intel_ssp: dai_ssp_pm_runtime_dis_ssp_power warning: timeout [00:00:12.894,946] dai_intel_ssp: dai_ssp_pm_runtime_dis_ssp_power: dai_ssp_pm_runtime_dis_ssp_power I2SLCTL [00:00:14.336,225] ipc: ipc_cmd: rx : 0x11000007|0x0 [00:00:14.336,245] pipe: pipeline_new: pipeline new pipe_id 0 priority 0 [00:00:14.336,685] ipc: ipc_cmd: rx : 0x40000004|0x15 [00:00:14.336,730] dma: dma_get: dma_get() ID 0 sref = 1 busy channels 0 [00:00:14.337,453] ipc: ipc_cmd: rx : 0x40000006|0x10 [00:00:14.338,395] ipc: ipc_cmd: rx : 0x44000006|0x30000018 [00:00:14.338,818] ipc: ipc_cmd: rx : 0x40000002|0xa [00:00:14.339,408] ipc: ipc_cmd: rx : 0x11010006|0x0 [00:00:14.339,423] pipe: pipeline_new: pipeline new pipe_id 1 priority 0 [00:00:14.339,838] ipc: ipc_cmd: rx : 0x40000003|0x1000a [00:00:14.340,658] ipc: ipc_cmd: rx : 0x40010006|0x10010 [00:00:14.341,221] ipc: ipc_cmd: rx : 0x44010006|0x30000018 [00:00:14.341,700] ipc: ipc_cmd: rx : 0x40010004|0x1002f [00:00:14.341,761] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power: dai_ssp_pm_runtime_en_ssp_power en_ssp_power index 0 [00:00:14.341,900] dai_intel_ssp: dai_ssp_poll_for_register_delay poll timeout reg 165892 mask 256 val 0 us 125 [00:00:14.341,923] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power warning: timeout [00:00:14.341,930] dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power: dai_ssp_pm_runtime_en_ssp_power I2SLCTL [00:00:14.341,943] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 28000, reg 8, mask 80, value 80 [00:00:14.341,968] dma: dma_get: dma_get() ID 0 sref = 1 busy channels 0 [00:00:14.341,983] ipc: dai_config: comp:1 0x40001 dai_config() dai type = 1 index = 0 dd 0x40115200 [00:00:14.342,003] dai_intel_ssp: dai_ssp_parse_aux_data: dai_ssp_parse_aux_data link clock_source 1 [00:00:14.342,020] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config sscr0 = 0xc1d0077f, sscr1 = 0xd0700004, ssto = 0x00000000, sspsp = 0x2200000 [00:00:14.342,033] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config sscr2 = 0x00004002, sspsp2 = 0x00000000, sscr3 = 0x07070000 [00:00:14.342,046] dai_intel_ssp: dai_ssp_set_reg_config: dai_ssp_set_reg_config ssioc = 0x00000020, ssrsa = 0x00000003, sstsa = 0x00000003 [00:00:14.342,060] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 28000, reg 4, mask 300000, value 300000 [00:00:14.342,071] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 28000, reg 0, mask 80, value 80 [00:00:14.342,835] ipc: ipc_cmd: rx : 0x45000004|0x6 [00:00:14.342,851] ipc: buffer_new: buffer new size 0x300 id 0.0 flags 0x0 [00:00:14.342,876] pipe: pipeline_connect: comp:0 0x40000 connect buffer 0 as sink [00:00:14.342,890] pipe: pipeline_connect: comp:0 0x60000 connect buffer 0 as source [00:00:14.343,656] ipc: ipc_cmd: rx : 0x45000006|0x2 [00:00:14.343,673] ipc: buffer_new: buffer new size 0x300 id 0.0 flags 0x0 [00:00:14.343,696] pipe: pipeline_connect: comp:0 0x60000 connect buffer 0 as sink [00:00:14.343,710] pipe: pipeline_connect: comp:0 0x20000 connect buffer 0 as source [00:00:14.344,380] ipc: ipc_cmd: rx : 0x45000002|0x3 [00:00:14.344,396] ipc: buffer_new: buffer new size 0x300 id 0.0 flags 0x0 [00:00:14.344,421] pipe: pipeline_connect: comp:0 0x20000 connect buffer 0 as sink [00:00:14.344,435] pipe: pipeline_connect: comp:1 0x30000 connect buffer 0 as source [00:00:14.344,865] ipc: ipc_cmd: rx : 0x45000003|0x10006 [00:00:14.344,883] ipc: buffer_new: buffer new size 0x300 id 1.0 flags 0x0 [00:00:14.344,906] pipe: pipeline_connect: comp:1 0x30000 connect buffer 0 as sink [00:00:14.344,920] pipe: pipeline_connect: comp:1 0x60001 connect buffer 0 as source [00:00:14.345,373] ipc: ipc_cmd: rx : 0x45010006|0x10004 [00:00:14.345,391] ipc: buffer_new: buffer new size 0x300 id 1.0 flags 0x0 [00:00:14.345,426] pipe: pipeline_connect: comp:1 0x60001 connect buffer 0 as sink [00:00:14.345,440] pipe: pipeline_connect: comp:1 0x40001 connect buffer 0 as source [00:00:14.347,633] ipc: ipc_cmd: rx : 0x13000003|0x1 [00:00:14.347,680] ipc: ipc_pipeline_complete(): no scheduling component specified, use comp 131072 [00:00:14.348,256] ipc: ipc_cmd: rx : 0x13000004|0x1 [00:00:14.348,310] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 0 [00:00:14.348,318] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 163856 [00:00:14.348,326] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 2 [00:00:14.348,336] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:14.348,356] dai_comp: dai_playback_params: comp:1 0x40001 dai_playback_params() dest_dev = 2 stream_id = 0 src_width = 4 dest_width = 4 [00:00:14.348,366] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 0 [00:00:14.348,375] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 163856 [00:00:14.348,383] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 2 [00:00:14.348,391] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:14.348,496] pipe: pipeline_trigger: pipe:1 0x0 pipe trigger cmd 7 [00:00:14.348,516] ll_schedule: zephyr_ll_task_schedule_common: task add 0xa0116f00 0x201b0U priority 0 flags 0x0 [00:00:14.348,560] ll_schedule: zephyr_domain_register: zephyr_domain_register domain->type 1 domain->clk 3 domain->ticks_per_ms 38400 period 1000 [00:00:14.348,686] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties dai_index 0 [00:00:14.348,695] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties fifo 163856 [00:00:14.348,703] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties handshake 2 [00:00:14.348,713] dai_intel_ssp: dai_ssp_get_properties: dai_ssp_get_properties init delay 0 [00:00:14.348,725] dai_intel_ssp: dai_ssp_pre_start: dai_ssp_pre_start [00:00:14.348,756] dma_intel_adsp_gpdma: intel_adsp_gpdma_power_on: intel_adsp_gpdma_power_on: dma dma@7c000 initialized [00:00:14.348,788] dai_intel_ssp: dai_ssp_start: dai_ssp_start [00:00:14.348,800] dai_intel_ssp: dai_ssp_update_bits: dai_ssp_update_bits base 28000, reg 30, mask 100, value 100 [00:00:14.348,953] mixer: mixin_prepare: comp:0 0x20000 mixin_prepare() [00:00:14.348,986] pipe: pipeline_trigger: pipe:0 0x0 pipe trigger cmd 7 [00:00:14.349,010] ll_schedule: zephyr_ll_task_schedule_common: task add 0xa01181c0 0x201b0U priority 0 flags 0x0 [00:00:14.349,778] host_comp: host_get_copy_bytes_normal: comp:0 0x40000 no bytes to copy, available samples: 0, free_samples: 192 [00:00:14.350,798] ipc: ipc_cmd: rx : 0x47000000|0x0 [00:00:14.351,721] ipc: ipc_cmd: rx : 0x11020007|0x200000 [00:00:14.351,770] pipe: pipeline_new: pipeline new pipe_id 2 priority 0 [00:00:14.353,205] ipc: ipc_cmd: rx : 0x40020004|0x2020015 [00:00:14.353,281] dma: dma_get: dma_get() ID 0 sref = 2 busy channels 0 [00:00:14.353,995] ipc: ipc_cmd: rx : 0x40020006|0x2020010 [00:00:14.354,936] ipc: ipc_cmd: rx : 0x44020006|0x30000018 [00:00:14.355,756] ipc: ipc_cmd: rx : 0x40010002|0x202000a [00:00:14.356,408] ipc: ipc_cmd: rx : 0x11030006|0x200000 [00:00:14.356,461] pipe: pipeline_new: pipeline new pipe_id 3 priority 0 [00:00:14.356,930] ipc: ipc_cmd: rx : 0x40010003|0x203000a Terminated