Test iterations:
| # | Iteration name: | Exec time: |
|---|---|---|
| 1 | TestMixinMixout.test_01_18_mixers_max_outputs[channel_count_8-mixout_count_3] | 6.109s |
Test Errors / Exceptions
ERROR:File is completely silent (TestMixinMixout.test_01_18_mixers_max_outputs[channel_count_8-mixout_count_3]_2023_01_16_16_00_07_record_file_name_0.wav). Average samples amplitude: 0.00%.
ERROR:File is completely silent (TestMixinMixout.test_01_18_mixers_max_outputs[channel_count_8-mixout_count_3]_2023_01_16_16_00_07_record_file_name_1.wav). Average samples amplitude: 0.00%.
ERROR:File is completely silent (TestMixinMixout.test_01_18_mixers_max_outputs[channel_count_8-mixout_count_3]_2023_01_16_16_00_07_record_file_name_2.wav). Average samples amplitude: 0.00%.
442904.238943
<LogFile>C:\history\cAVS\01_18_TestMixinMixout\2023_01_16_16_00_05\log_lite.html
442904.240306
LogDir:
C:\history\cAVS\01_18_TestMixinMixout\2023_01_16_16_00_05
C:\history\cAVS\01_18_TestMixinMixout\2023_01_16_16_00_05
442904.240497
LogFile:
C:\history\cAVS\01_18_TestMixinMixout\2023_01_16_16_00_05\log_lite.html
C:\history\cAVS\01_18_TestMixinMixout\2023_01_16_16_00_05\log_lite.html
Logger 01_18_TestMixinMixout configuration
Configure AVS
Environment initialization
442904.243950
Setting environment FW_TYPE to: cAVS.
442904.244140
Opening dev audio...
442904.784128
Opening Audio device.
442904.787966
Audio device has been opened
442904.808354
Creating FW loader...
442904.822496
IpcLogFile:
C:\history\cAVS\01_18_TestMixinMixout\2023_01_16_16_00_05\ipc.log
C:\history\cAVS\01_18_TestMixinMixout\2023_01_16_16_00_05\ipc.log
442905.003890
IPC init version: IPC_ACE
442905.030214
Platform: Windows-10-10.0.22000-SP0
442905.030566
Running cmd: pnputil /enum-devices /connected
442905.186320
Platform: Windows-10-10.0.22000-SP0
442905.186613
Running cmd: pnputil /enum-drivers
442905.433537
Diagnostic driver version: 07/13/2022 10.0.0.54
442905.433937
Test controller initialized:
platform: MTL
fw_type: cAVS
prevent_power_gating: None
platform: MTL
fw_type: cAVS
prevent_power_gating: None
442905.434193
setting PCE.HAE = 1
Booting dsp
Loading base firmware
442905.438344
Trying to reinit FwLoader...
442905.438636
DSP panic discarded.
442905.438799
IpcDriver already initialized, skipping init
442905.438966
Path to firmware image:
442905.439124
C:\work_ace\res\fw\cSOF_zephyr\MTL\build-sof-staging\sof\community\sof-mtl.ri
442905.439298
FW version 2.0.0.1
442905.439489
--------------------------------------------------------------------------------
Booting DSP on platform MTL, FPGA mode: False
--------------------------------------------------------------------------------
Booting DSP on platform MTL, FPGA mode: False
--------------------------------------------------------------------------------
442905.439691
Try #1
442905.448137
START ManagerIOB::reset_all (() {})
442905.746539
END ManagerIOB::reset_all returned: None
442905.747445
Power DOWN DSP subsystem...
442905.748469
HfDSSCS.CPA is now RESETED. DSP domain is DOWN.
442905.749043
Power UP DSP subsystem...
442905.749817
HfDSSCS.CPA is now SET. DSP domain is UP.
442905.750357
HfIMRI registers: address 0x44000000, size 0x2000000 (set by BIOS)
442905.751338
HiFi4 #0 (master) core is already DOWN...
442905.751839
Expecting FW ready notification...
442905.753176
START IpcDriver::register_for_ipc ((<utilities.ipc.avs.callback_struct.IpcCallbackStruct object at 0x00000283BFB32DA0>,) {})
442905.753711
END IpcDriver::register_for_ipc returned: None
442905.754315
ROM control message: 0x81004000 dma_id = 0
442905.754854
Powering all cores. Mask = 0x7
442905.755497
Power HiFi4 #0 (master) core UP...
442905.756332
DSPCxCTL.CPA is now set. HiFi4 #0 (master) core is on.
442905.757209
HiFi4 #1 core is already DOWN...
442905.758056
HiFi4 #2 core is already DOWN...
442905.758518
Enabling cores.
442905.758981
Starting core 0
442905.759420
Waiting for ROM to clean ROM control IPC...
442905.760339
ROM status: 0x55000001
* Error: 0.
* Module: 0x5.
* Wait state: 0x5 (WAIT_FOR_DMA_BUFFER_FULL).
* Boot state: 0x000001 (ROM_INIT_DONE).
* Error: 0.
* Module: 0x5.
* Wait state: 0x5 (WAIT_FOR_DMA_BUFFER_FULL).
* Boot state: 0x000001 (ROM_INIT_DONE).
442905.761161
ROM control IPC acknowledged.
442905.864604
Waiting for ROM status: 0x05000000 ...
442905.864960
Status received:
442905.865140
ROM status: 0x55000001
* Error: 0.
* Module: 0x5.
* Wait state: 0x5 (WAIT_FOR_DMA_BUFFER_FULL).
* Boot state: 0x000001 (ROM_INIT_DONE).
* Error: 0.
* Module: 0x5.
* Wait state: 0x5 (WAIT_FOR_DMA_BUFFER_FULL).
* Boot state: 0x000001 (ROM_INIT_DONE).
442905.865301
Starting DMA
442905.866466
IOB ID: 10
SDCTL = 0x00140002
SDSTS = 0x00000000
SPIB = 0x000C4000
SDCBL = 0x000C4000
SDLPIB = 0x00000000
SDLVI = 0x000000C3
SDDPIB = 0x00001680
SDCTL = 0x00140002
SDSTS = 0x00000000
SPIB = 0x000C4000
SDCBL = 0x000C4000
SDLPIB = 0x00000000
SDLVI = 0x000000C3
SDDPIB = 0x00001680
442906.265340
Notification FwReadyNotification (9B080000, 00000000) received!
442906.271681
Calling registered callback...
442906.272592
FW ready notification recieved!
442906.273996
Clearing host busy bit
442906.274715
Setting host done bit
442906.276451
FW load time: 0.406
442906.277068
ROM start and FW load time: 0.516
442906.293659
START ManagerIOB::release_iob ((10,) {})
442906.309820
END ManagerIOB::release_iob returned: None
Basic test initialization
442906.311694
START IpcDriver::register_for_ipc ((<utilities.ipc.avs.callback_struct.IpcCallbackStruct object at 0x00000283BFB78250>,) {})
442906.312243
END IpcDriver::register_for_ipc returned: None
442906.313201
START IpcDriver::register_for_ipc ((<utilities.ipc.avs.callback_struct.IpcCallbackStruct object at 0x00000283BFB78760>,) {})
442906.313714
END IpcDriver::register_for_ipc returned: None
442906.314755
START IpcDriver::register_for_ipc ((<utilities.ipc.avs.callback_struct.IpcCallbackStruct object at 0x00000283BFB789D0>,) {})
442906.315200
END IpcDriver::register_for_ipc returned: None
442906.316766
START IpcDriver::send ((Ipc(0xC3000000, 0x30701000, []),) {})
442906.317594
FW status before message:
FW status: 0x00000005
Last error code: 0x00000000 (ADSP_SUCCESS)
FW status: 0x00000005
Last error code: 0x00000000 (ADSP_SUCCESS)
442906.318354
Sending LargeConfigGet (C3000000, 30701000)
Module: 0
Instance: 0
Large param: 7
Module: 0
Instance: 0
Large param: 7
442906.321817
START IpcDriver::block_on_response ((5.0,) {'expect_error': False, 'expected_reply_size': None, 'read_response_payload': True})
442906.323008
Clearing DSP done bit
442906.325293
Response LargeConfigGet (E3000000, 30700104)
Payload:
00000000 00000008 00000002 00010000
00000001 00000004 00000001 00000003
00000004 17D78400 00000002 00000004
17D78400 00000002 00000004 00010000
00000015 00000004 00000000 00000005
00000004 00010000 00000006 00000004
00002000 00000007 00000004 00001000
00000008 00000004 00001000 00000009
00000004 00000010 0000000A 00000004
00000003 0000000B 00000004 00000008
0000000D 00000004 00000100 0000000E
00000004 00000010 0000000F 00000004
00000008 00000010 00000004 00000010
0000000C 00000004 00000005 00000011
00000004 00000010 00000012 00000014
00000001 00000001 00000001 00000000
000028C0 received!
Payload:
00000000 00000008 00000002 00010000
00000001 00000004 00000001 00000003
00000004 17D78400 00000002 00000004
17D78400 00000002 00000004 00010000
00000015 00000004 00000000 00000005
00000004 00010000 00000006 00000004
00002000 00000007 00000004 00001000
00000008 00000004 00001000 00000009
00000004 00000010 0000000A 00000004
00000003 0000000B 00000004 00000008
0000000D 00000004 00000100 0000000E
00000004 00000010 0000000F 00000004
00000008 00000010 00000004 00000010
0000000C 00000004 00000005 00000011
00000004 00000010 00000012 00000014
00000001 00000001 00000001 00000000
000028C0 received!
442906.330604
Clearing DSP done bit
442906.331096
Clearing host busy bit
442906.331503
Setting host done bit
442906.332179
FW status after message:
FW status: 0x00000005
Last error code: 0x00000000 (ADSP_SUCCESS)
FW status: 0x00000005
Last error code: 0x00000000 (ADSP_SUCCESS)
442906.333460
END IpcDriver::block_on_response returned: LargeConfigGet (E3000000, 30700104)
Payload:
00000000 00000008 00000002 00010000
00000001 00000004 00000001 00000003
00000004 17D78400 00000002 00000004
17D78400 00000002 00000004 00010000
00000015 00000004 00000000 00000005
00000004 00010000 00000006 00000004
00002000 00000007 00000004 00001000
00000008 00000004 00001000 00000009
00000004 00000010 0000000A 00000004
00000003 0000000B 00000004 00000008
0000000D 00000004 00000100 0000000E
00000004 00000010 0000000F 00000004
00000008 00000010 00000004 00000010
0000000C 00000004 00000005 00000011
00000004 00000010 00000012 00000014
00000001 00000001 00000001 00000000
000028C0
Payload:
00000000 00000008 00000002 00010000
00000001 00000004 00000001 00000003
00000004 17D78400 00000002 00000004
17D78400 00000002 00000004 00010000
00000015 00000004 00000000 00000005
00000004 00010000 00000006 00000004
00002000 00000007 00000004 00001000
00000008 00000004 00001000 00000009
00000004 00000010 0000000A 00000004
00000003 0000000B 00000004 00000008
0000000D 00000004 00000100 0000000E
00000004 00000010 0000000F 00000004
00000008 00000010 00000004 00000010
0000000C 00000004 00000005 00000011
00000004 00000010 00000012 00000014
00000001 00000001 00000001 00000000
000028C0
442906.334501
END IpcDriver::send returned: LargeConfigGet (E3000000, 30700104)
Payload:
00000000 00000008 00000002 00010000
00000001 00000004 00000001 00000003
00000004 17D78400 00000002 00000004
17D78400 00000002 00000004 00010000
00000015 00000004 00000000 00000005
00000004 00010000 00000006 00000004
00002000 00000007 00000004 00001000
00000008 00000004 00001000 00000009
00000004 00000010 0000000A 00000004
00000003 0000000B 00000004 00000008
0000000D 00000004 00000100 0000000E
00000004 00000010 0000000F 00000004
00000008 00000010 00000004 00000010
0000000C 00000004 00000005 00000011
00000004 00000010 00000012 00000014
00000001 00000001 00000001 00000000
000028C0
Payload:
00000000 00000008 00000002 00010000
00000001 00000004 00000001 00000003
00000004 17D78400 00000002 00000004
17D78400 00000002 00000004 00010000
00000015 00000004 00000000 00000005
00000004 00010000 00000006 00000004
00002000 00000007 00000004 00001000
00000008 00000004 00001000 00000009
00000004 00000010 0000000A 00000004
00000003 0000000B 00000004 00000008
0000000D 00000004 00000100 0000000E
00000004 00000010 0000000F 00000004
00000008 00000010 00000004 00000010
0000000C 00000004 00000005 00000011
00000004 00000010 00000012 00000014
00000001 00000001 00000001 00000000
000028C0
442906.337160
FW version:
Major: 0x0002 (2)
Minor: 0x0000 (0)
Hotfix: 0x0000 (0)
Build: 0x0001 (1)
Major: 0x0002 (2)
Minor: 0x0000 (0)
Hotfix: 0x0000 (0)
Build: 0x0001 (1)
442906.338005
START IpcDriver::send ((Ipc(0xC3000000, 0x30801000, []),) {})
442906.339125
FW status before message:
FW status: 0x00000005
Last error code: 0x00000000 (ADSP_SUCCESS)
FW status: 0x00000005
Last error code: 0x00000000 (ADSP_SUCCESS)
442906.339784
Sending LargeConfigGet (C3000000, 30801000)
Module: 0
Instance: 0
Large param: 8
Module: 0
Instance: 0
Large param: 8
442906.341534
START IpcDriver::block_on_response ((5.0,) {'expect_error': False, 'expected_reply_size': None, 'read_response_payload': True})
442906.342516
Clearing DSP done bit
442906.343944
Response LargeConfigGet (E3000000, 30800060)
Payload:
00000000 00000004 00010500 00000001
00000004 00000003 00000002 00000004
00001000 00000009 00000004 00020000
00000003 00000004 00000400 00000007
00000004 00000016 00000006 00000004
0000002B 00000008 00000004 00000000 received!
Payload:
00000000 00000004 00010500 00000001
00000004 00000003 00000002 00000004
00001000 00000009 00000004 00020000
00000003 00000004 00000400 00000007
00000004 00000016 00000006 00000004
0000002B 00000008 00000004 00000000 received!
442906.345187
Clearing DSP done bit
442906.345638
Clearing host busy bit
442906.346045
Setting host done bit
442906.346695
FW status after message:
FW status: 0x00000005
Last error code: 0x00000000 (ADSP_SUCCESS)
FW status: 0x00000005
Last error code: 0x00000000 (ADSP_SUCCESS)
442906.347803
END IpcDriver::block_on_response returned: LargeConfigGet (E3000000, 30800060)
Payload:
00000000 00000004 00010500 00000001
00000004 00000003 00000002 00000004
00001000 00000009 00000004 00020000
00000003 00000004 00000400 00000007
00000004 00000016 00000006 00000004
0000002B 00000008 00000004 00000000
Payload:
00000000 00000004 00010500 00000001
00000004 00000003 00000002 00000004
00001000 00000009 00000004 00020000
00000003 00000004 00000400 00000007
00000004 00000016 00000006 00000004
0000002B 00000008 00000004 00000000
442906.348748
END IpcDriver::send returned: LargeConfigGet (E3000000, 30800060)
Payload:
00000000 00000004 00010500 00000001
00000004 00000003 00000002 00000004
00001000 00000009 00000004 00020000
00000003 00000004 00000400 00000007
00000004 00000016 00000006 00000004
0000002B 00000008 00000004 00000000
Payload:
00000000 00000004 00010500 00000001
00000004 00000003 00000002 00000004
00001000 00000009 00000004 00020000
00000003 00000004 00000400 00000007
00000004 00000016 00000006 00000004
0000002B 00000008 00000004 00000000
442906.350863
cAVS version:
Major: 0x0001 (1)
Minor: 0x0500 (1280)
Major: 0x0001 (1)
Minor: 0x0500 (1280)
Configuring Base Firmware
442906.353039
XTAL set to 38.4 MHz
442906.354151
START IpcDriver::send ((Ipc(0xC4000000, 0x3070000C, [0x00000013, 0x00000004, 0x0249F000]),) {})
442906.355246
FW status before message:
FW status: 0x00000005
Last error code: 0x00000000 (ADSP_SUCCESS)
FW status: 0x00000005
Last error code: 0x00000000 (ADSP_SUCCESS)
442906.356358
Sending LargeConfigSet (C4000000, 3070000C)
Payload:
00000013 00000004 0249F000
Module: 0
Instance: 0
Large param: 7
Payload:
00000013 00000004 0249F000
Module: 0
Instance: 0
Large param: 7
442906.358355
START IpcDriver::block_on_response ((5.0,) {'expect_error': False, 'expected_reply_size': None, 'read_response_payload': True})
442906.359409
Clearing DSP done bit
442906.360355
Response LargeConfigSet (E4000000, 3070000C) received!
442906.361466
Clearing DSP done bit
442906.361929
Clearing host busy bit
442906.362374
Setting host done bit
442906.363071
FW status after message:
FW status: 0x00000005
Last error code: 0x00000000 (ADSP_SUCCESS)
FW status: 0x00000005
Last error code: 0x00000000 (ADSP_SUCCESS)
442906.364041
END IpcDriver::block_on_response returned: LargeConfigSet (E4000000, 3070000C)
442906.364803
END IpcDriver::send returned: LargeConfigSet (E4000000, 3070000C)
442906.365556
Set power gating policy to 3840
442906.366505
START IpcDriver::send ((Ipc(0xC4000000, 0x3070000C, [0x00000016, 0x00000004, 0x00000F00]),) {})
442906.367281
FW status before message:
FW status: 0x00000005
Last error code: 0x00000000 (ADSP_SUCCESS)
FW status: 0x00000005
Last error code: 0x00000000 (ADSP_SUCCESS)
442906.368265
Sending LargeConfigSet (C4000000, 3070000C)
Payload:
00000016 00000004 00000F00
Module: 0
Instance: 0
Large param: 7
Payload:
00000016 00000004 00000F00
Module: 0
Instance: 0
Large param: 7
442906.369925
START IpcDriver::block_on_response ((5.0,) {'expect_error': False, 'expected_reply_size': None, 'read_response_payload': True})
442906.370886
Clearing DSP done bit
442906.371824
Response LargeConfigSet (E4000000, 3070000C) received!
442906.373141
Clearing DSP done bit
442906.373618
Clearing host busy bit
442906.374096
Setting host done bit
442906.374814
FW status after message:
FW status: 0x00000005
Last error code: 0x00000000 (ADSP_SUCCESS)
FW status: 0x00000005
Last error code: 0x00000000 (ADSP_SUCCESS)
442906.375755
END IpcDriver::block_on_response returned: LargeConfigSet (E4000000, 3070000C)
442906.376534
END IpcDriver::send returned: LargeConfigSet (E4000000, 3070000C)
Test cleanup.
442912.498802
START IpcDriver::unregister_ipc_callback ((<utilities.ipc.avs.callback_struct.IpcCallbackStruct object at 0x00000283BFB789D0>,) {})
442912.499017
END IpcDriver::unregister_ipc_callback returned: None
442912.499347
Cleaning up environment.
442912.499485
Closing IPC Driver.
442912.499628
IpcDriver.stop() fired. Stopping threads.
442912.509862
Stopping all hda streamers.
442912.516708
Audio device has been closed