[1500936996.979167] ( 248.333328) c0 ll-schedule ./schedule/ll_schedule.c:345 task add 0x9e126480 dma-trace-task <2b972272-c5b1-4b7e-926f-0fc5cb4c4690> [1500937014.166667] ( 17.187500) c0 ll-schedule ./schedule/ll_schedule.c:349 task params pri 4 flags 0 start 500000 period 500000 [1500937034.322917] ( 20.156250) c0 ll-schedule ./schedule/ll_schedule.c:252 num_tasks 2 total_num_tasks 2 [1500937614.218750] ( 579.895813) c0 component src/audio/component.c:130 comp new host <8b9d100c-6d78-418f-90a3-e0e805d0852b> type 1 id 1.1 [1500937659.427083] ( 45.208332) c0 hda-dma ..../intel/hda/hda-dma.c:794 hda-dmac :5 -> probe [1500937757.864583] ( 98.437500) c0 dma src/lib/dma.c:127 dma_get() ID 5 sref = 1 busy channels 0 [1500938618.750000] ( 860.885437) c0 component src/audio/component.c:130 comp new pga type 5 id 1.2 [1500938660.156250] ( 41.406250) c0 pga 1.2 ../audio/volume/volume.c:379 vol->initial_ramp = 20, vol->ramp = 2, vol->min_value = 0, vol->max_value = 65536 [1500939183.697917] ( 523.541687) c0 buffer src/audio/buffer.c:79 buffer new size 0x300 id 1.3 flags 0x0 [1500939668.906250] ( 485.208344) c0 buffer src/audio/buffer.c:79 buffer new size 0x300 id 1.4 flags 0x0 [1500940224.791667] ( 555.885437) c0 component src/audio/component.c:130 comp new dai type 2 id 1.5 [1500940266.770833] ( 41.979168) c0 hda-dai 3.0 /drivers/intel/hda/hda.c:65 hda_probe() [1500940290.156250] ( 23.385416) c0 dai src/lib/dai.c:165 dai_get type 3 index 0 new sref 1 [1500940312.343750] ( 22.187500) c0 hda-dma ..../intel/hda/hda-dma.c:794 hda-dmac :7 -> probe [1500940396.614583] ( 84.270836) c0 dma src/lib/dma.c:127 dma_get() ID 7 sref = 1 busy channels 0 [1500940763.854167] ( 367.239594) c0 sa src/lib/agent.c:79 WARN validate(), ll drift detected, delta = 41515 [1500941141.510417] ( 377.656250) c0 pipe src/audio/pipeline.c:78 pipeline new pipe_id 1 period 1000 priority 0 [1500941696.354167] ( 554.843750) c0 component src/audio/component.c:130 comp new host <8b9d100c-6d78-418f-90a3-e0e805d0852b> type 1 id 2.9 [1500941740.000000] ( 43.645832) c0 dma src/lib/dma.c:127 dma_get() ID 4 sref = 2 busy channels 1 [1500942308.020833] ( 568.020813) c0 component src/audio/component.c:130 comp new pga type 5 id 2.10 [1500942349.635417] ( 41.614582) c0 pga 2.10 ../audio/volume/volume.c:379 vol->initial_ramp = 250, vol->ramp = 0, vol->min_value = 0, vol->max_value = 2072775 [1500942814.218750] ( 464.583344) c0 buffer src/audio/buffer.c:79 buffer new size 0x300 id 2.11 flags 0x0 [1500943393.854167] ( 579.635437) c0 buffer src/audio/buffer.c:79 buffer new size 0x300 id 2.12 flags 0x0 [1500944010.416667] ( 616.562500) c0 component src/audio/component.c:130 comp new dai type 2 id 2.13 [1500944051.510417] ( 41.093750) c0 hda-dai 3.1 /drivers/intel/hda/hda.c:65 hda_probe() [1500944074.635417] ( 23.125000) c0 dai src/lib/dai.c:165 dai_get type 3 index 1 new sref 1 [1500944096.875000] ( 22.239584) c0 hda-dma ..../intel/hda/hda-dma.c:794 hda-dmac :6 -> probe [1500944196.822917] ( 99.947914) c0 dma src/lib/dma.c:127 dma_get() ID 6 sref = 1 busy channels 0 [1500944776.250000] ( 579.427063) c0 pipe src/audio/pipeline.c:78 pipeline new pipe_id 2 period 1000 priority 0 [1500945421.875000] ( 645.625000) c0 component src/audio/component.c:130 comp new host <8b9d100c-6d78-418f-90a3-e0e805d0852b> type 1 id 3.17 [1500945465.625000] ( 43.750000) c0 dma src/lib/dma.c:127 dma_get() ID 5 sref = 2 busy channels 0 [1500946094.375000] ( 628.750000) c0 component src/audio/component.c:130 comp new pga type 5 id 3.18 [1500946135.677083] ( 41.302082) c0 pga 3.18 ../audio/volume/volume.c:379 vol->initial_ramp = 20, vol->ramp = 2, vol->min_value = 0, vol->max_value = 65536 [1500946845.260417] ( 709.583313) c0 buffer src/audio/buffer.c:79 buffer new size 0x300 id 3.19 flags 0x0 [1500947545.520833] ( 700.260437) c0 buffer src/audio/buffer.c:79 buffer new size 0x300 id 3.20 flags 0x0 [1500948162.708333] ( 617.187500) c0 component src/audio/component.c:130 comp new dai type 2 id 3.21 [1500948204.166667] ( 41.458332) c0 hda-dai 3.2 /drivers/intel/hda/hda.c:65 hda_probe() [1500948227.395833] ( 23.229166) c0 dai src/lib/dai.c:165 dai_get type 3 index 2 new sref 1 [1500948249.270833] ( 21.875000) c0 dma src/lib/dma.c:127 dma_get() ID 7 sref = 2 busy channels 0 [1500948813.854167] ( 564.583313) c0 pipe src/audio/pipeline.c:78 pipeline new pipe_id 3 period 1000 priority 0 [1500949451.510417] ( 637.656250) c0 component src/audio/component.c:130 comp new host <8b9d100c-6d78-418f-90a3-e0e805d0852b> type 1 id 4.25 [1500949495.104167] ( 43.593750) c0 dma src/lib/dma.c:127 dma_get() ID 4 sref = 3 busy channels 1 [1500950125.052083] ( 629.947937) c0 component src/audio/component.c:130 comp new pga type 5 id 4.26 [1500950166.510417] ( 41.458332) c0 pga 4.26 ../audio/volume/volume.c:379 vol->initial_ramp = 250, vol->ramp = 0, vol->min_value = 0, vol->max_value = 2072775 [1500950813.072917] ( 646.562500) c0 buffer src/audio/buffer.c:79 buffer new size 0x300 id 4.27 flags 0x0 [1500951453.593750] ( 640.520813) c0 buffer src/audio/buffer.c:79 buffer new size 0x300 id 4.28 flags 0x0 [1500951948.020833] ( 494.427094) c0 component src/audio/component.c:130 comp new dai type 2 id 4.29 [1500951989.739583] ( 41.718750) c0 hda-dai 3.3 /drivers/intel/hda/hda.c:65 hda_probe() [1500952013.125000] ( 23.385416) c0 dai src/lib/dai.c:165 dai_get type 3 index 3 new sref 1 [1500952035.208333] ( 22.083334) c0 dma src/lib/dma.c:127 dma_get() ID 6 sref = 2 busy channels 0 [1500952609.427083] ( 574.218750) c0 pipe src/audio/pipeline.c:78 pipeline new pipe_id 4 period 1000 priority 0 [1500953115.052083] ( 505.625000) c0 component src/audio/component.c:130 comp new host <8b9d100c-6d78-418f-90a3-e0e805d0852b> type 1 id 7.37 [1500953158.645833] ( 43.593750) c0 dma src/lib/dma.c:127 dma_get() ID 5 sref = 3 busy channels 0 [1500953665.625000] ( 506.979156) c0 component src/audio/component.c:130 comp new pga type 5 id 7.38 [1500953706.822917] ( 41.197918) c0 pga 7.38 ../audio/volume/volume.c:379 vol->initial_ramp = 20, vol->ramp = 2, vol->min_value = 0, vol->max_value = 65536 [1500954202.864583] ( 496.041656) c0 buffer src/audio/buffer.c:79 buffer new size 0x300 id 7.39 flags 0x0 [1500954805.104167] ( 602.239563) c0 sa src/lib/agent.c:79 WARN validate(), ll drift detected, delta = 42577 [1500954858.750000] ( 53.645832) c0 buffer src/audio/buffer.c:79 buffer new size 0x300 id 7.40 flags 0x0 [1500955371.093750] ( 512.343750) c0 component src/audio/component.c:130 comp new dai type 2 id 7.41 [1500955413.177083] ( 42.083332) c0 hda-dai 3.4 /drivers/intel/hda/hda.c:65 hda_probe() [1500955436.458333] ( 23.281250) c0 dai src/lib/dai.c:165 dai_get type 3 index 4 new sref 1 [1500955458.541667] ( 22.083334) c0 dma src/lib/dma.c:127 dma_get() ID 7 sref = 3 busy channels 0 [1500955937.291667] ( 478.750000) c0 pipe src/audio/pipeline.c:78 pipeline new pipe_id 7 period 1000 priority 0 [1500956685.729167] ( 748.437500) c0 component src/audio/component.c:130 comp new host <8b9d100c-6d78-418f-90a3-e0e805d0852b> type 1 id 8.45 [1500956728.958333] ( 43.229168) c0 dma src/lib/dma.c:127 dma_get() ID 5 sref = 4 busy channels 0 [1500957390.260417] ( 661.302063) c0 component src/audio/component.c:130 comp new pga type 5 id 8.46 [1500957431.197917] ( 40.937500) c0 pga 8.46 ../audio/volume/volume.c:379 vol->initial_ramp = 20, vol->ramp = 2, vol->min_value = 0, vol->max_value = 65536 [1500957928.697917] ( 497.500000) c0 buffer src/audio/buffer.c:79 buffer new size 0x300 id 8.47 flags 0x0 [1500958475.468750] ( 546.770813) c0 buffer src/audio/buffer.c:79 buffer new size 0x300 id 8.48 flags 0x0 [1500958772.968750] ( 297.500000) c0 sa src/lib/agent.c:79 WARN validate(), ll drift detected, delta = 41029 [1500958833.489583] ( 60.520832) c0 component src/audio/component.c:130 comp new dai type 2 id 8.49 [1500958876.979167] ( 43.489582) c0 hda-dai 3.5 /drivers/intel/hda/hda.c:65 hda_probe() [1500958900.260417] ( 23.281250) c0 dai src/lib/dai.c:165 dai_get type 3 index 5 new sref 1 [1500958922.447917] ( 22.187500) c0 dma src/lib/dma.c:127 dma_get() ID 7 sref = 4 busy channels 0 [1500959360.885417] ( 438.437500) c0 pipe src/audio/pipeline.c:78 pipeline new pipe_id 8 period 1000 priority 0 [1500959832.239583] ( 471.354156) c0 component src/audio/component.c:130 comp new host <8b9d100c-6d78-418f-90a3-e0e805d0852b> type 1 id 9.53 [1500959875.677083] ( 43.437500) c0 dma src/lib/dma.c:127 dma_get() ID 5 sref = 5 busy channels 0 [1500960382.395833] ( 506.718750) c0 component src/audio/component.c:130 comp new pga type 5 id 9.54 [1500960423.645833] ( 41.250000) c0 pga 9.54 ../audio/volume/volume.c:379 vol->initial_ramp = 20, vol->ramp = 2, vol->min_value = 0, vol->max_value = 65536 [1500960889.322917] ( 465.677094) c0 buffer src/audio/buffer.c:79 buffer new size 0x300 id 9.55 flags 0x0 [1500961346.458333] ( 457.135406) c0 buffer src/audio/buffer.c:79 buffer new size 0x300 id 9.56 flags 0x0 [1500961840.989583] ( 494.531250) c0 component src/audio/component.c:130 comp new dai type 2 id 9.57 [1500961883.072917] ( 42.083332) c0 hda-dai 3.6 /drivers/intel/hda/hda.c:65 hda_probe() [1500961906.406250] ( 23.333334) c0 dai src/lib/dai.c:165 dai_get type 3 index 6 new sref 1 [1500961928.125000] ( 21.718750) c0 dma src/lib/dma.c:127 dma_get() ID 7 sref = 5 busy channels 0 [1500962418.437500] ( 490.312500) c0 pipe src/audio/pipeline.c:78 pipeline new pipe_id 9 period 1000 priority 0 [1500962854.270833] ( 435.833344) c0 component src/audio/component.c:130 comp new host <8b9d100c-6d78-418f-90a3-e0e805d0852b> type 1 id 10.60 [1500962897.552083] ( 43.281250) c0 dma src/lib/dma.c:127 dma_get() ID 4 sref = 4 busy channels 1 [1500963363.645833] ( 466.093750) c0 buffer src/audio/buffer.c:79 buffer new size 0x600 id 10.61 flags 0x0 [1500963916.927083] ( 553.281250) c0 component src/audio/component.c:130 comp new dai type 2 id 10.62 [1500963958.645833] ( 41.718750) c0 dmic-dai 2.0 src/drivers/intel/dmic.c:1569 dmic_probe() [1500964016.979167] ( 58.333332) c0 dai src/lib/dai.c:165 dai_get type 2 index 0 new sref 1 [1500964121.250000] ( 104.270836) c0 dma src/lib/dma.c:127 dma_get() ID 0 sref = 1 busy channels 0 [1500964706.510417] ( 585.260437) c0 pipe src/audio/pipeline.c:78 pipeline new pipe_id 10 period 1000 priority 0 [1500965207.708333] ( 501.197906) c0 component src/audio/component.c:130 comp new host <8b9d100c-6d78-418f-90a3-e0e805d0852b> type 1 id 11.64 [1500965251.145833] ( 43.437500) c0 dma src/lib/dma.c:127 dma_get() ID 4 sref = 5 busy channels 1 [1500965757.812500] ( 506.666656) c0 component src/audio/component.c:130 comp new pga type 5 id 11.65 [1500965798.802083] ( 40.989582) c0 pga 11.65 ../audio/volume/volume.c:379 vol->initial_ramp = 250, vol->ramp = 0, vol->min_value = 0, vol->max_value = 2072775 [1500966299.322917] ( 500.520844) c0 component src/audio/component.c:130 comp new kpb type 16 id 11.66 [1500966317.395833] ( 18.072916) c0 kpb src/audio/kpb.c:135 kpb_new() [1500966770.000000] ( 452.604156) c0 sa src/lib/agent.c:79 WARN validate(), ll drift detected, delta = 41027 [1500966831.041667] ( 61.041668) c0 buffer src/audio/buffer.c:79 buffer new size 0x1e00 id 11.67 flags 0x0 [1500967393.489583] ( 562.447937) c0 buffer src/audio/buffer.c:79 buffer new size 0x1400 id 11.68 flags 0x0 [1500967879.739583] ( 486.250000) c0 buffer src/audio/buffer.c:79 buffer new size 0x1400 id 11.69 flags 0x0 [1500968314.218750] ( 434.479156) c0 component src/audio/component.c:130 comp new dai type 2 id 11.70 [1500968355.989583] ( 41.770832) c0 dmic-dai 2.1 src/drivers/intel/dmic.c:1569 dmic_probe() [1500968409.218750] ( 53.229168) c0 dai src/lib/dai.c:165 dai_get type 2 index 1 new sref 1 [1500968513.541667] ( 104.322914) c0 dma src/lib/dma.c:127 dma_get() ID 1 sref = 1 busy channels 0 [1500968865.000000] ( 351.458344) c0 pipe src/audio/pipeline.c:78 pipeline new pipe_id 11 period 20000 priority 0 [1500969200.104167] ( 335.104156) c0 component src/audio/component.c:130 comp new kd-test type 15 id 12.72 [1500969217.500000] ( 17.395834) c0 kd-test ..../audio/detect_test.c:256 test_keyword_new() [1500969719.583333] ( 502.083344) c0 component src/audio/component.c:130 comp new selector <55a88ed5-3d18-46ca-88f1-0ee6eae9930f> type 17 id 12.73 [1500969737.656250] ( 18.072916) c0 selector ..../selector/selector.c:61 selector_new() [1500970202.604167] ( 464.947906) c0 buffer src/audio/buffer.c:79 buffer new size 0x1400 id 12.74 flags 0x0 [1500970719.531250] ( 516.927063) c0 buffer src/audio/buffer.c:79 buffer new size 0x1400 id 12.75 flags 0x0 [1500971219.166667] ( 499.635406) c0 pipe src/audio/pipeline.c:78 pipeline new pipe_id 12 period 20000 priority 1 [1500971679.739583] ( 460.572906) c0 kpb 11.66 src/audio/pipeline.c:125 connect buffer 74 as sink [1500972076.614583] ( 396.875000) c0 host 1.1 src/audio/pipeline.c:125 connect buffer 3 as sink [1500972503.854167] ( 427.239594) c0 pga 1.2 src/audio/pipeline.c:127 connect buffer 3 as source [1500972809.375000] ( 305.520844) c0 sa src/lib/agent.c:79 WARN validate(), ll drift detected, delta = 40990 [1500972855.156250] ( 45.781250) c0 pga 1.2 src/audio/pipeline.c:125 connect buffer 4 as sink [1500973238.906250] ( 383.750000) c0 dai 1.5 src/audio/pipeline.c:127 connect buffer 4 as source [1500973605.468750] ( 366.562500) c0 host 2.9 src/audio/pipeline.c:127 connect buffer 11 as source [1500974033.020833] ( 427.552094) c0 pga 2.10 src/audio/pipeline.c:125 connect buffer 11 as sink [1500974400.625000] ( 367.604156) c0 pga 2.10 src/audio/pipeline.c:127 connect buffer 12 as source [1500974794.062500] ( 393.437500) c0 dai 2.13 src/audio/pipeline.c:125 connect buffer 12 as sink [1500975196.406250] ( 402.343750) c0 host 3.17 src/audio/pipeline.c:125 connect buffer 19 as sink [1500975684.635417] ( 488.229156) c0 pga 3.18 src/audio/pipeline.c:127 connect buffer 19 as source [1500976051.197917] ( 366.562500) c0 pga 3.18 src/audio/pipeline.c:125 connect buffer 20 as sink [1500976418.072917] ( 366.875000) c0 dai 3.21 src/audio/pipeline.c:127 connect buffer 20 as source [1500976813.697917] ( 395.625000) c0 host 4.25 src/audio/pipeline.c:127 connect buffer 27 as source [1500977214.375000] ( 400.677094) c0 pga 4.26 src/audio/pipeline.c:125 connect buffer 27 as sink [1500977641.302083] ( 426.927094) c0 pga 4.26 src/audio/pipeline.c:127 connect buffer 28 as source [1500978069.739583] ( 428.437500) c0 dai 4.29 src/audio/pipeline.c:125 connect buffer 28 as sink [1500978438.229167] ( 368.489594) c0 host 7.37 src/audio/pipeline.c:125 connect buffer 39 as sink [1500978899.322917] ( 461.093750) c0 pga 7.38 src/audio/pipeline.c:127 connect buffer 39 as source [1500979293.125000] ( 393.802094) c0 pga 7.38 src/audio/pipeline.c:125 connect buffer 40 as sink [1500979720.885417] ( 427.760406) c0 dai 7.41 src/audio/pipeline.c:127 connect buffer 40 as source [1500980089.427083] ( 368.541656) c0 host 8.45 src/audio/pipeline.c:125 connect buffer 47 as sink [1500980516.770833] ( 427.343750) c0 pga 8.46 src/audio/pipeline.c:127 connect buffer 47 as source [1500980849.687500] ( 332.916656) c0 pga 8.46 src/audio/pipeline.c:125 connect buffer 48 as sink [1500981250.312500] ( 400.625000) c0 dai 8.49 src/audio/pipeline.c:127 connect buffer 48 as source [1500981679.843750] ( 429.531250) c0 host 9.53 src/audio/pipeline.c:125 connect buffer 55 as sink [1500982107.083333] ( 427.239594) c0 pga 9.54 src/audio/pipeline.c:127 connect buffer 55 as source [1500982534.687500] ( 427.604156) c0 pga 9.54 src/audio/pipeline.c:125 connect buffer 56 as sink [1500982901.822917] ( 367.135406) c0 dai 9.57 src/audio/pipeline.c:127 connect buffer 56 as source [1500983330.833333] ( 429.010406) c0 host 10.60 src/audio/pipeline.c:127 connect buffer 61 as source [1500983697.604167] ( 366.770844) c0 dai 10.62 src/audio/pipeline.c:125 connect buffer 61 as sink [1500984127.187500] ( 429.583344) c0 host 11.64 src/audio/pipeline.c:127 connect buffer 69 as source [1500984555.364583] ( 428.177094) c0 kpb 11.66 src/audio/pipeline.c:125 connect buffer 69 as sink [1500984982.083333] ( 426.718750) c0 kpb 11.66 src/audio/pipeline.c:127 connect buffer 68 as source [1500985409.010417] ( 426.927094) c0 pga 11.65 src/audio/pipeline.c:125 connect buffer 68 as sink [1500985836.041667] ( 427.031250) c0 pga 11.65 src/audio/pipeline.c:127 connect buffer 67 as source [1500986265.312500] ( 429.270844) c0 dai 11.70 src/audio/pipeline.c:125 connect buffer 67 as sink [1500986724.010417] ( 458.697906) c0 sa src/lib/agent.c:79 WARN validate(), ll drift detected, delta = 41027 [1500986800.000000] ( 75.989586) c0 kd-test 12.72 src/audio/pipeline.c:127 connect buffer 75 as source [1500987185.312500] ( 385.312500) c0 selector 12.73 src/audio/pipeline.c:125 connect buffer 75 as sink [1500987610.208333] ( 424.895844) c0 selector 12.73 src/audio/pipeline.c:127 connect buffer 74 as source [1500988074.531250] ( 464.322906) c0 dai src/lib/dai.c:165 dai_get type 3 index 0 new sref 2 [1500988095.364583] ( 20.833334) c0 dai src/lib/dai.c:191 dai_put type 3 index 0 new sref 1 [1500988118.385417] ( 23.020834) c0 dai 1.5 src/audio/dai.c:891 dai_config() dai type = 3 index = 0 [1500988136.875000] ( 18.489584) c0 dai 1.5 src/audio/dai.c:923 dai_config(), channel = -1 [1500988778.177083] ( 641.302063) c0 dai src/lib/dai.c:165 dai_get type 3 index 1 new sref 2 [1500988798.020833] ( 19.843750) c0 dai src/lib/dai.c:191 dai_put type 3 index 1 new sref 1 [1500988823.593750] ( 25.572916) c0 dai 2.13 src/audio/dai.c:891 dai_config() dai type = 3 index = 1 [1500988841.458333] ( 17.864584) c0 dai 2.13 src/audio/dai.c:923 dai_config(), channel = -1 [1500989360.052083] ( 518.593750) c0 dai src/lib/dai.c:165 dai_get type 3 index 2 new sref 2 [1500989379.687500] ( 19.635416) c0 dai src/lib/dai.c:191 dai_put type 3 index 2 new sref 1 [1500989408.645833] ( 28.958334) c0 dai 3.21 src/audio/dai.c:891 dai_config() dai type = 3 index = 2 [1500989426.562500] ( 17.916666) c0 dai 3.21 src/audio/dai.c:923 dai_config(), channel = -1 [1500989908.958333] ( 482.395844) c0 dai src/lib/dai.c:165 dai_get type 3 index 3 new sref 2 [1500989928.593750] ( 19.635416) c0 dai src/lib/dai.c:191 dai_put type 3 index 3 new sref 1 [1500989960.937500] ( 32.343750) c0 dai 4.29 src/audio/dai.c:891 dai_config() dai type = 3 index = 3 [1500989978.750000] ( 17.812500) c0 dai 4.29 src/audio/dai.c:923 dai_config(), channel = -1 [1500990519.635417] ( 540.885437) c0 dai src/lib/dai.c:165 dai_get type 3 index 4 new sref 2 [1500990539.531250] ( 19.895834) c0 dai src/lib/dai.c:191 dai_put type 3 index 4 new sref 1 [1500990608.854167] ( 69.322914) c0 dai 7.41 src/audio/dai.c:891 dai_config() dai type = 3 index = 4 [1500990628.385417] ( 19.531250) c0 dai 7.41 src/audio/dai.c:923 dai_config(), channel = -1 [1500991127.187500] ( 498.802094) c0 dai src/lib/dai.c:165 dai_get type 3 index 5 new sref 2 [1500991147.187500] ( 20.000000) c0 dai src/lib/dai.c:191 dai_put type 3 index 5 new sref 1 [1500991185.833333] ( 38.645832) c0 dai 8.49 src/audio/dai.c:891 dai_config() dai type = 3 index = 5 [1500991205.364583] ( 19.531250) c0 dai 8.49 src/audio/dai.c:923 dai_config(), channel = -1 [1500991677.864583] ( 472.500000) c0 dai src/lib/dai.c:165 dai_get type 3 index 6 new sref 2 [1500991697.500000] ( 19.635416) c0 dai src/lib/dai.c:191 dai_put type 3 index 6 new sref 1 [1500991739.687500] ( 42.187500) c0 dai 9.57 src/audio/dai.c:891 dai_config() dai type = 3 index = 6 [1500991759.010417] ( 19.322916) c0 dai 9.57 src/audio/dai.c:923 dai_config(), channel = -1 [1500992287.812500] ( 528.802063) c0 dai src/lib/dai.c:165 dai_get type 2 index 0 new sref 2 [1500992306.041667] ( 18.229166) c0 dmic-dai 2.0 src/drivers/intel/dmic.c:1112 dmic_set_config() [1500992333.020833] ( 26.979166) c0 dmic-dai 2.0 src/drivers/intel/dmic.c:1152 dmic_set_config(): unmute_ramp_time_ms = 200 [1500992372.916667] ( 39.895832) c0 dmic-dai 2.0 src/drivers/intel/dmic.c:1200 dmic_set_config(), prm config->dmic.num_pdm_active = 2 [1500992391.354167] ( 18.437500) c0 dmic-dai 2.0 src/drivers/intel/dmic.c:1202 dmic_set_config(), prm pdmclk_min = 500000, pdmclk_max = 4800000 [1500992408.229167] ( 16.875000) c0 dmic-dai 2.0 src/drivers/intel/dmic.c:1204 dmic_set_config(), prm duty_min = 40, duty_max = 60 [1500992426.562500] ( 18.333334) c0 dmic-dai 2.0 src/drivers/intel/dmic.c:1206 dmic_set_config(), prm fifo_fs = 48000, fifo_bits = 32 [1500992485.937500] ( 59.375000) c0 dmic-dai 2.0 src/drivers/intel/dmic.c:1248 dmic_set_config(), cfg clkdiv = 16, mcic = 25 [1500992504.218750] ( 18.281250) c0 dmic-dai 2.0 src/drivers/intel/dmic.c:1250 dmic_set_config(), cfg mfir_a = 2, mfir_b = 0 [1500992522.604167] ( 18.385416) c0 dmic-dai 2.0 src/drivers/intel/dmic.c:1252 dmic_set_config(), cfg cic_shift = 3 [1500992539.010417] ( 16.406250) c0 dmic-dai 2.0 src/drivers/intel/dmic.c:1254 dmic_set_config(), cfg fir_a_shift = 0, cfg.fir_b_shift = 0 [1500992555.677083] ( 16.666666) c0 dmic-dai 2.0 src/drivers/intel/dmic.c:1256 dmic_set_config(), cfg fir_a_length = 101, fir_b_length = 0 [1500992615.312500] ( 59.635418) c0 dmic-dai 2.0 src/drivers/intel/dmic.c:836 configuring registers [1500992699.375000] ( 84.062500) c0 dai src/lib/dai.c:191 dai_put type 2 index 0 new sref 1 [1500992745.729167] ( 46.354168) c0 dai 10.62 src/audio/dai.c:891 dai_config() dai type = 2 index = 0 [1500992763.958333] ( 18.229166) c0 dai 10.62 src/audio/dai.c:919 dai_config(), config->dmic.fifo_bits = 32 config->dmic.num_pdm_active = 2 [1500992782.916667] ( 18.958334) c0 dw-dma src/drivers/dw/dma.c:191 dw_dma_channel_get(): dma 0 request channel 0 [1500993327.656250] ( 544.739563) c0 dai src/lib/dai.c:165 dai_get type 2 index 1 new sref 2 [1500993345.989583] ( 18.333334) c0 dmic-dai 2.1 src/drivers/intel/dmic.c:1112 dmic_set_config() [1500993371.770833] ( 25.781250) c0 dmic-dai 2.1 src/drivers/intel/dmic.c:1152 dmic_set_config(): unmute_ramp_time_ms = 400 [1500993395.156250] ( 23.385416) c0 dmic-dai 2.1 src/drivers/intel/dmic.c:1200 dmic_set_config(), prm config->dmic.num_pdm_active = 1 [1500993413.541667] ( 18.385416) c0 dmic-dai 2.1 src/drivers/intel/dmic.c:1202 dmic_set_config(), prm pdmclk_min = 500000, pdmclk_max = 4800000 [1500993431.770833] ( 18.229166) c0 dmic-dai 2.1 src/drivers/intel/dmic.c:1204 dmic_set_config(), prm duty_min = 40, duty_max = 60 [1500993448.489583] ( 16.718750) c0 dmic-dai 2.1 src/drivers/intel/dmic.c:1206 dmic_set_config(), prm fifo_fs = 16000, fifo_bits = 32 [1500993608.906250] ( 160.416672) c0 dmic-dai 2.1 src/drivers/intel/dmic.c:1248 dmic_set_config(), cfg clkdiv = 16, mcic = 25 [1500993625.572917] ( 16.666666) c0 dmic-dai 2.1 src/drivers/intel/dmic.c:1250 dmic_set_config(), cfg mfir_a = 2, mfir_b = 6 [1500993642.395833] ( 16.822916) c0 dmic-dai 2.1 src/drivers/intel/dmic.c:1252 dmic_set_config(), cfg cic_shift = 3 [1500993658.854167] ( 16.458334) c0 dmic-dai 2.1 src/drivers/intel/dmic.c:1254 dmic_set_config(), cfg fir_a_shift = 0, cfg.fir_b_shift = 1 [1500993675.625000] ( 16.770834) c0 dmic-dai 2.1 src/drivers/intel/dmic.c:1256 dmic_set_config(), cfg fir_a_length = 101, fir_b_length = 249 [1500993694.166667] ( 18.541666) c0 dmic-dai 2.1 src/drivers/intel/dmic.c:836 configuring registers [1500993909.843750] ( 215.677078) c0 dai src/lib/dai.c:191 dai_put type 2 index 1 new sref 1 [1500993960.052083] ( 50.208332) c0 dai 11.70 src/audio/dai.c:891 dai_config() dai type = 2 index = 1 [1500993978.489583] ( 18.437500) c0 dai 11.70 src/audio/dai.c:919 dai_config(), config->dmic.fifo_bits = 32 config->dmic.num_pdm_active = 1 [1500993997.135417] ( 18.645834) c0 dw-dma src/drivers/dw/dma.c:191 dw_dma_channel_get(): dma 1 request channel 0 [1500994608.593750] ( 611.458313) c0 pipe 12.77 src/audio/pipeline.c:246 pipeline complete, clock freq 400000000Hz [1500994627.760417] ( 19.166666) c0 memory src/lib/alloc.c:1151 heap: buffer status [1500994645.260417] ( 17.500000) c0 memory src/lib/alloc.c:1120 heap: 0xbe08f800 size 524288 blocks 1 caps 0x71 [1500994662.239583] ( 16.979166) c0 memory src/lib/alloc.c:1122 used 71680 free 452608 [1500994678.854167] ( 16.614584) c0 memory src/lib/alloc.c:1120 heap: 0xbe8003b0 size 64592 blocks 1 caps 0x69 [1500994696.979167] ( 18.125000) c0 memory src/lib/alloc.c:1122 used 0 free 64592 [1500994715.260417] ( 18.281250) c0 memory src/lib/alloc.c:1153 heap: runtime status [1500994731.041667] ( 15.781250) c0 memory src/lib/alloc.c:1120 heap: 0xbe080000 size 63488 blocks 7 caps 0x45 [1500994747.916667] ( 16.875000) c0 memory src/lib/alloc.c:1122 used 18560 free 44928 [1500994764.791667] ( 16.875000) c0 memory src/lib/alloc.c:1130 block 1 base 0xbe082000 size 128 [1500994781.875000] ( 17.083334) c0 memory src/lib/alloc.c:1133 count 64 free 34 [1500994798.802083] ( 16.927084) c0 memory src/lib/alloc.c:1130 block 2 base 0xbe084000 size 256 [1500994817.500000] ( 18.697916) c0 memory src/lib/alloc.c:1133 count 128 free 71 [1500994834.166667] ( 16.666666) c0 memory src/lib/alloc.c:1130 block 3 base 0xbe08c000 size 512 [1500994851.250000] ( 17.083334) c0 memory src/lib/alloc.c:1133 count 8 free 8 [1500994866.666667] ( 15.416667) c0 memory src/lib/alloc.c:1130 block 4 base 0xbe08d000 size 1024 [1500994883.750000] ( 17.083334) c0 memory src/lib/alloc.c:1133 count 4 free 4 [1500994934.010417] ( 50.260418) c0 memory src/lib/alloc.c:1156 heap: runtime shared status [1500994950.677083] ( 16.666666) c0 memory src/lib/alloc.c:1120 heap: 0x9e11d000 size 37888 blocks 5 caps 0x45 [1500994967.812500] ( 17.135416) c0 memory src/lib/alloc.c:1122 used 13056 free 24832 [1500995505.260417] ( 537.447937) c0 dma-trace src/trace/trace.c:142 Suppressed 6 similar messages: block %d base 0x%x size %d [1500995517.760417] ( 12.500000) c0 dma-trace src/trace/trace.c:142 Suppressed 6 similar messages: count %d free %d [1500995530.520833] ( 12.760417) c0 pipe 11.71 src/audio/pipeline.c:246 pipeline complete, clock freq 400000000Hz [1500995990.520833] ( 460.000000) c0 pipe 10.63 src/audio/pipeline.c:246 pipeline complete, clock freq 400000000Hz [1500996412.291667] ( 421.770844) c0 pipe 9.58 src/audio/pipeline.c:246 pipeline complete, clock freq 400000000Hz [1500996794.739583] ( 382.447906) c0 sa src/lib/agent.c:79 WARN validate(), ll drift detected, delta = 42360 [1500996879.895833] ( 85.156250) c0 pipe 8.50 src/audio/pipeline.c:246 pipeline complete, clock freq 400000000Hz [1500997252.812500] ( 372.916656) c0 pipe 7.42 src/audio/pipeline.c:246 pipeline complete, clock freq 400000000Hz [1500997672.708333] ( 419.895844) c0 pipe 4.30 src/audio/pipeline.c:246 pipeline complete, clock freq 400000000Hz [1500998092.447917] ( 419.739594) c0 pipe 3.22 src/audio/pipeline.c:246 pipeline complete, clock freq 400000000Hz [1500998663.125000] ( 570.677063) c0 pipe 2.14 src/audio/pipeline.c:246 pipeline complete, clock freq 400000000Hz [1500998994.322917] ( 331.197906) c0 pipe 1.6 src/audio/pipeline.c:246 pipeline complete, clock freq 400000000Hz [1500999433.645833] ( 439.322906) c0 selector 12.73 ..../selector/selector.c:322 selector_cmd() [1500999451.562500] ( 17.916666) c0 selector 12.73 ..../selector/selector.c:251 selector_ctrl_set_data(), SOF_CTRL_CMD_BINARY [1501000228.281250] ( 776.718750) c0 kd-test 12.72 ..../audio/detect_test.c:556 test_keyword_cmd() [1501000246.770833] ( 18.489584) c0 kd-test 12.72 ..../audio/detect_test.c:470 test_keyword_cmd_set_data(), SOF_CTRL_CMD_BINARY [1501000764.114583] ( 517.343750) c0 sa src/lib/agent.c:79 WARN validate(), ll drift detected, delta = 41026 [1501000823.437500] ( 59.322918) c0 kd-test 12.72 ..../audio/detect_test.c:556 test_keyword_cmd() [1501000842.916667] ( 19.479166) c0 kd-test 12.72 ..../audio/detect_test.c:470 test_keyword_cmd_set_data(), SOF_CTRL_CMD_BINARY [1501000860.416667] ( 17.500000) c0 kd-test 12.72 ..../audio/detect_test.c:410 test_keyword_set_config(), blob size = 32 [1501002486.197917] ( 1625.781250) c0 pga 11.65 ../audio/volume/volume.c:561 volume_ctrl_set_cmd(), channel = 0, value = 20723 [1501002503.489583] ( 17.291666) c0 pga 11.65 ../audio/volume/volume.c:561 volume_ctrl_set_cmd(), channel = 1, value = 20723 [1501002813.177083] ( 309.687500) c0 pga 9.54 ../audio/volume/volume.c:561 volume_ctrl_set_cmd(), channel = 0, value = 65536 [1501002830.312500] ( 17.135416) c0 pga 9.54 ../audio/volume/volume.c:561 volume_ctrl_set_cmd(), channel = 1, value = 65536 [1501003515.520833] ( 685.208313) c0 pga 8.46 ../audio/volume/volume.c:561 volume_ctrl_set_cmd(), channel = 0, value = 65536 [1501003533.020833] ( 17.500000) c0 pga 8.46 ../audio/volume/volume.c:561 volume_ctrl_set_cmd(), channel = 1, value = 65536 [1501004246.093750] ( 713.072937) c0 pga 7.38 ../audio/volume/volume.c:561 volume_ctrl_set_cmd(), channel = 0, value = 65536 [1501004262.552083] ( 16.458334) c0 pga 7.38 ../audio/volume/volume.c:561 volume_ctrl_set_cmd(), channel = 1, value = 65536 [1501004820.885417] ( 558.333313) c0 pga 4.26 ../audio/volume/volume.c:561 volume_ctrl_set_cmd(), channel = 0, value = 2072775 [1501004838.125000] ( 17.239584) c0 pga 4.26 ../audio/volume/volume.c:561 volume_ctrl_set_cmd(), channel = 1, value = 2072775 [1501005463.593750] ( 625.468750) c0 pga 3.18 ../audio/volume/volume.c:561 volume_ctrl_set_cmd(), channel = 0, value = 65536 [1501005480.781250] ( 17.187500) c0 pga 3.18 ../audio/volume/volume.c:561 volume_ctrl_set_cmd(), channel = 1, value = 65536 [1501006133.020833] ( 652.239563) c0 pga 2.10 ../audio/volume/volume.c:561 volume_ctrl_set_cmd(), channel = 0, value = 2072775 [1501006149.583333] ( 16.562500) c0 pga 2.10 ../audio/volume/volume.c:561 volume_ctrl_set_cmd(), channel = 1, value = 2072775 [1501006829.947917] ( 680.364563) c0 pga 1.2 ../audio/volume/volume.c:561 volume_ctrl_set_cmd(), channel = 0, value = 65536 [1501006846.927083] ( 16.979166) c0 pga 1.2 ../audio/volume/volume.c:561 volume_ctrl_set_cmd(), channel = 1, value = 65536 [1501007469.843750] ( 622.916687) c0 ipc src/ipc/handler.c:606 ipc: pm -> restore [1501008407.916667] ( 938.072937) c0 pipe 11.71 src/audio/pipeline.c:538 pipe params dir 1 frame_fmt 0 buffer_fmt 0 rate 16000 [1501008426.250000] ( 18.333334) c0 pipe 11.71 src/audio/pipeline.c:542 pipe params stream_tag 2 channels 2 sample_valid_bytes 2 sample_container_bytes 2 [1501008670.208333] ( 243.958328) c0 dai 11.70 src/audio/dai.c:412 dai_capture_params() src_dev = 1 stream_id = 0 src_width = 4 dest_width = 4 [1501008688.645833] ( 18.437500) c0 dai 11.70 src/audio/dai.c:418 dai_capture_params() fifo 0x10108 [1501008715.781250] ( 27.135416) c0 pipe 11.71 src/audio/pipeline.c:669 pipe prepare [1501008820.937500] ( 105.156250) c0 kpb 11.66 src/audio/kpb.c:435 kpb_prepare() [1501008839.531250] ( 18.593750) c0 kpb src/audio/kpb.c:219 kpb_allocate_history_buffer() [1501010152.968750] ( 1313.437500) c0 kpb src/audio/kpb.c:246 kpb new memory block: 64256 [1501010501.822917] ( 348.854156) c0 kpb src/audio/kpb.c:246 kpb new memory block: 127744 [1501010517.760417] ( 15.937500) c0 kpb src/audio/kpb.c:295 kpb_allocate_history_buffer(): allocated 192000 bytes [1501010534.479167] ( 16.718750) c0 kpb src/audio/kpb.c:1520 kpb_reset_history_buffer() [1501010550.729167] ( 16.250000) c0 kpb src/audio/kpb.c:1415 kpb_clear_history_buffer() [1501013972.812500] ( 3422.083252) c0 pipe 12.77 src/audio/pipeline.c:538 pipe params dir 1 frame_fmt 0 buffer_fmt 0 rate 16000 [1501013994.687500] ( 21.875000) c0 pipe 12.77 src/audio/pipeline.c:542 pipe params stream_tag 0 channels 2 sample_valid_bytes 2 sample_container_bytes 0 [1501014032.343750] ( 37.656250) c0 selector 12.73 ..../selector/selector.c:225 selector_params() [1501014061.562500] ( 29.218750) c0 kpb 11.66 src/audio/kpb.c:401 ERROR kpb_params(): kpb has been already configured. [1501014084.947917] ( 23.385416) c0 pipe 12.77 src/audio/pipeline.c:669 pipe prepare [1501014118.802083] ( 33.854168) c0 kd-test 12.72 ..../audio/detect_test.c:639 test_keyword_prepare() [1501014226.197917] ( 107.395836) c0 selector 12.73 ..../selector/selector.c:435 selector_prepare() [1501014242.916667] ( 16.718750) c0 selector 12.73 ..../selector/selector.c:465 selector_prepare(): sourceb->schannels = 2 [1501014258.645833] ( 15.729167) c0 selector 12.73 ..../selector/selector.c:467 selector_prepare(): sinkb->channels = 1 [1501014339.322917] ( 80.677086) c0 kpb 11.66 src/audio/kpb.c:435 kpb_prepare() [1501014357.500000] ( 18.177084) c0 kpb 11.66 src/audio/component.c:180 comp_set_state(), state already set to 3 [1501014743.750000] ( 386.250000) c0 sa src/lib/agent.c:79 WARN validate(), ll drift detected, delta = 41331 [1501014803.072917] ( 59.322918) c0 pipe 12.77 src/audio/pipeline.c:864 pipe trigger cmd 1 [1501014821.458333] ( 18.385416) c0 kd-test 12.72 ..../audio/detect_test.c:573 test_keyword_trigger() [1501014839.635417] ( 18.177084) c0 selector 12.73 ..../selector/selector.c:356 selector_trigger() [1501014859.687500] ( 20.052084) c0 ll-schedule ./schedule/ll_schedule.c:345 task add 0xbe0801c0 pipe-task [1501014876.406250] ( 16.718750) c0 ll-schedule ./schedule/ll_schedule.c:349 task params pri 1 flags 0 start 0 period 20000 [1501014897.604167] ( 21.197916) c0 ll-schedule ./schedule/ll_schedule.c:252 num_tasks 3 total_num_tasks 3 [1501016523.906250] ( 1626.302124) c0 pipe 11.71 src/audio/pipeline.c:864 pipe trigger cmd 1 [1501016725.885417] ( 201.979172) c0 kpb 11.66 src/audio/kpb.c:367 kpb_trigger() [1501016758.177083] ( 32.291668) c0 dmic-dai 2.1 src/drivers/intel/dmic.c:1307 dmic_start(), dmic->fifo_b [1501016776.614583] ( 18.437500) c0 dmic-dai 2.1 src/drivers/intel/dmic.c:1333 dmic_start(), mic_a = 1, mic_b = 1, fir_a = 1, fir_b = 1 [1501016795.156250] ( 18.541666) c0 dmic-dai 2.1 src/drivers/intel/dmic.c:1333 dmic_start(), mic_a = 0, mic_b = 0, fir_a = 0, fir_b = 0 [1501016816.145833] ( 20.989584) c0 ll-schedule ./schedule/ll_schedule.c:345 task add 0x9e120908 dmic-work <59c87728-d8f9-42f6-b89d-5870a87b0e1e> [1501016833.281250] ( 17.135416) c0 ll-schedule ./schedule/ll_schedule.c:349 task params pri 4 flags 0 start 1000 period 1000 [1501016855.312500] ( 22.031250) c0 ll-schedule ./schedule/ll_schedule.c:252 num_tasks 4 total_num_tasks 4 [1501016875.625000] ( 20.312500) c0 dmic-dai 2.1 src/drivers/intel/dmic.c:1405 dmic_start(), done active_fifos = 1 [1501016904.947917] ( 29.322916) c0 ll-schedule ./schedule/ll_schedule.c:345 task add 0xbe080100 pipe-task [1501016923.906250] ( 18.958334) c0 ll-schedule ./schedule/ll_schedule.c:349 task params pri 0 flags 0 start 0 period 20000 [1501016944.687500] ( 20.781250) c0 ll-schedule ./schedule/ll_schedule.c:252 num_tasks 5 total_num_tasks 5 [1501018774.791667] ( 1830.104126) c0 sa src/lib/agent.c:79 WARN validate(), ll drift detected, delta = 40979 [1501820811.145833] ( 802036.375000) c0 ll-schedule ./schedule/ll_schedule.c:124 task complete 0x9e120908 dmic-work <59c87728-d8f9-42f6-b89d-5870a87b0e1e> [1501820829.218750] ( 18.072916) c0 ll-schedule ./schedule/ll_schedule.c:127 num_tasks 4 total_num_tasks 4 [1503106892.239583] ( 1286063.000000) c0 sa src/lib/agent.c:79 WARN validate(), ll drift detected, delta = 41015 [1503284923.645833] ( 178031.406250) c0 sa src/lib/agent.c:79 WARN validate(), ll drift detected, delta = 41009 [1508896890.937500] ( 5611967.500000) c0 kd-test 12.72 ..../audio/detect_test.c:113 notify_host() [1508896915.989583] ( 25.052084) c0 kd-test 12.72 ..../audio/detect_test.c:122 notify_kpb(), preamble: 33600 [1508896933.489583] ( 17.500000) c0 kpb 11.66 src/audio/kpb.c:926 kpb_event_handler(): received event with ID: 2 [1508896951.875000] ( 18.385416) c0 kpb 11.66 src/audio/kpb.c:1021 kpb_init_draining(): requested draining of 2000 [ms] from history buffer [1508896971.979167] ( 20.104166) c0 kpb 11.66 src/audio/kpb.c:1118 kpb_init_draining: unlimited draining speed selected. [1508896988.229167] ( 16.250000) c0 kpb 11.66 src/audio/kpb.c:1121 kpb_init_draining(), schedule draining task [1508897038.385417] ( 50.156250) c0 kpb src/audio/kpb.c:1182 kpb_draining_task(), start. [1508904294.895833] ( 7256.510254) c0 kpb src/audio/kpb.c:1269 kpb: update drain_req by 1264 [1508904396.770833] ( 101.875000) c0 kpb src/audio/kpb.c:1269 kpb: update drain_req by 0 [1508904416.875000] ( 20.104166) c0 kpb src/audio/kpb.c:1296 KPB: kpb_draining_task(), done. 129264 drained in 3 ms [1508904791.093750] ( 374.218750) c0 sa src/lib/agent.c:79 WARN validate(), ll drift detected, delta = 42198