On 09/08/16 13:41, Peter Ujfalusi wrote:
> On 09/08/16 06:53, Tony Lindgren wrote:
>> * Peter Ujfalusi <peter.ujfalusi@xxxxxx> [160907 07:32]:
>>> On 09/06/2016 11:16 PM, Tony Lindgren wrote:
>>>> Makes sense. Do you have a formula or updated patch I can test here?
>>>> Then we can add comments about the possible unaccounted latencies that
>>>> can be worked out as needed.
>>>
>>> Not yet, but I'll try to come up with something in the coming days.
>>
>> OK
>
> I managed to get time for this and it looks like that we only need to block
> core OFF for audio. I don't know why C6 ("MPU OFF + CORE RET") with it's 3000
> + 8500 exit latency not causing issues when we have less time from the DMA
> request to empty FIFO...
>
> My findings so far:
> w/o the QoS patch we will hit core OFF even if we are in element mode in McBSP:
> # cat /sys/devices/platform/68000000.ocp/49022000.mcbsp/dma_op_mode
> [element] threshold
>
> If I start the playback we will hit core OFF even if the we have DMA request
> coming at every sample (every 0.02ms).
>
> With the QoS set to 30ms and:
> # cat /sys/devices/platform/68000000.ocp/49022000.mcbsp/dma_op_mode
> element [threshold]
> # cat /sys/devices/platform/68000000.ocp/49022000.mcbsp/max_tx_thres
> 1264
>
> # cat /sys/kernel/debug/pm_debug/count; aplay -Dplughw:0,0
> media/music/nin-echoplex.wav; cat /sys/kernel/debug/pm_debug/count
>
> core_pwrdm
> (ON),OFF:1885,RET:6777,INA:86320,ON:94983,RET-LOGIC-OFF:0,RET-MEMBANK1-OFF:0,RET-MEMBANK2-OFF:0
> per_pwrdm (ON),OFF:2507,RET:1518,INA:0,ON:4026,RET-LOGIC-OFF:0,RET-MEMBANK1-OFF:0
> mpu_pwrdm
> (ON),OFF:80588,RET:7876,INA:97390,ON:185855,RET-LOGIC-OFF:0,RET-MEMBANK1-OFF:0
>
> Playing WAVE 'media/music/nin-echoplex.wav' : Signed 16 bit Little Endian,
> Rate 48000 Hz, Stereo
>
> core_pwrdm
> (ON),OFF:1885,RET:7860,INA:107434,ON:117180,RET-LOGIC-OFF:0,RET-MEMBANK1-OFF:0,RET-MEMBANK2-OFF:0
> per_pwrdm (ON),OFF:2507,RET:1518,INA:0,ON:4026,RET-LOGIC-OFF:0,RET-MEMBANK1-OFF:0
> mpu_pwrdm
> (ON),OFF:103223,RET:8185,INA:97461,ON:208870,RET-LOGIC-OFF:0,RET-MEMBANK1-OFF:0
>
> We hit C6, but when the DMA request comes we have 16 words in the FIFO (8
> samples, 0.16ms of audio). C6 should take 11.5ms to exit...
>
>>> btw: I have tried the idle off on beagbeboard-xm with audio, but even w/o the
>>> qos it is not triggering. w/o audio I hit off but if audio is running, not.
>>
>> OK yeah figured it out you need to comment out the watch -n5 command
>> as that keeps the serial console busy :) I was doing it over ssh earlier
>> on the torpedo board.
>>
>>> btw2: if you set the qos to 30ms and set the mcbsp2 threshold to 1024 (or
>>> leave it as default) do you have audio glitches? I think if we hit C6 we
>>> should not be able to wake up in time...
>>
>> Not that I've noticed at least with the default fifo size. How can
>> I force the threshold to 1024? I tried changing pkt_size for
>> omap_mcbsp_set_threshold but not getting any audio.
>
> Based on my experiments the FIFO threshold does not matter as even if we
> should not be able to leave from a C state in time, we do leave from the state :o
>
> The patch generates the following warning when the playback is stopped:
> [ 115.726531]
> [ 115.728149] =================================
> [ 115.732727] [ INFO: inconsistent lock state ]
> [ 115.737304] 4.8.0-rc3-next-20160825-00064-g957cf3635c39-dirty #1450 Not tainted
> [ 115.744964] ---------------------------------
> [ 115.749542] inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
> [ 115.755859] swapper/0/0 [HC0[0]:SC1[1]:HE0:SE0] takes:
> [ 115.761230] ((&(&req->work)->work)){+.?...}, at: [<c0152fe0>]
> flush_work+0x0/0x260
> [ 115.769348] {SOFTIRQ-ON-W} state was registered at:
> [ 115.774475] [<c015301c>] flush_work+0x3c/0x260
> [ 115.779357] [<c0155b74>] __cancel_work_timer+0x90/0x1c0
> [ 115.785034] [<c01999c8>] pm_qos_update_request+0x28/0x54
> [ 115.790802] [<c01549ec>] process_one_work+0x1fc/0x770
> [ 115.796295] [<c0154f98>] worker_thread+0x38/0x550
> [ 115.801452] [<c015b0b8>] kthread+0xd4/0xf0
> [ 115.805969] [<c0107910>] ret_from_fork+0x14/0x24
> [ 115.811004] irq event stamp: 191097
> [ 115.814666] hardirqs last enabled at (191096): [<c07f8fb8>]
> _raw_spin_unlock_irq+0x24/0x2c
> [ 115.823455] hardirqs last disabled at (191097): [<c0663f30>]
> _snd_pcm_stream_lock_irqsave+0x2c/0x40
> [ 115.832977] softirqs last enabled at (191090): [<c013e5dc>]
> irq_enter+0x68/0x84
> [ 115.840759] softirqs last disabled at (191091): [<c013e6b8>]
> irq_exit+0xc0/0x134
> [ 115.848541]
> [ 115.848541] other info that might help us debug this:
> [ 115.855407] Possible unsafe locking scenario:
> [ 115.855407]
> [ 115.861602] CPU0
> [ 115.864166] ----
> [ 115.866760] lock((&(&req->work)->work));
> [ 115.871063] <Interrupt>
> [ 115.873809] lock((&(&req->work)->work));
> [ 115.878326]
> [ 115.878326] *** DEADLOCK ***
> [ 115.878326]
> [ 115.884552] 2 locks held by swapper/0/0:
> [ 115.888671] #0: (snd_pcm_link_rwlock){...-..}, at: [<c0663e9c>]
> snd_pcm_stream_lock+0x20/0x50
> [ 115.897857] #1: (&(&substream->self_group.lock)->rlock){..-...}, at:
> [<c0663f38>] _snd_pcm_stream_lock_irqsave+0x34/0x40
> [ 115.909515]
> [ 115.909515] stack backtrace:
> [ 115.914123] CPU: 0 PID: 0 Comm: swapper/0 Not tainted
> 4.8.0-rc3-next-20160825-00064-g957cf3635c39-dirty #1450
> [ 115.924530] Hardware name: Generic OMAP36xx (Flattened Device Tree)
> [ 115.931121] [<c0110128>] (unwind_backtrace) from [<c010c2c0>]
> (show_stack+0x10/0x14)
> [ 115.939270] [<c010c2c0>] (show_stack) from [<c048c120>] (dump_stack+0xb0/0xe4)
> [ 115.946868] [<c048c120>] (dump_stack) from [<c0192708>]
> (print_usage_bug+0x1e0/0x2d4)
> [ 115.955108] [<c0192708>] (print_usage_bug) from [<c0192d7c>]
> (mark_lock+0x580/0x6c4)
> [ 115.963256] [<c0192d7c>] (mark_lock) from [<c0193a38>]
> (__lock_acquire+0x5a8/0x187c)
> [ 115.971374] [<c0193a38>] (__lock_acquire) from [<c0195128>]
> (lock_acquire+0xd0/0x238)
> [ 115.979614] [<c0195128>] (lock_acquire) from [<c015301c>]
> (flush_work+0x3c/0x260)
> [ 115.987487] [<c015301c>] (flush_work) from [<c0155b74>]
> (__cancel_work_timer+0x90/0x1c0)
> [ 115.996002] [<c0155b74>] (__cancel_work_timer) from [<c0199ad8>]
> (pm_qos_remove_request+0x28/0x1c8)
> [ 116.005523] [<c0199ad8>] (pm_qos_remove_request) from [<c0684634>]
> (omap_mcbsp_dai_trigger+0x70/0x8c)
> [ 116.015197] [<c0684634>] (omap_mcbsp_dai_trigger) from [<c067baa8>]
> (soc_pcm_trigger+0xd0/0x11c)
> [ 116.024414] [<c067baa8>] (soc_pcm_trigger) from [<c0663be0>]
> (snd_pcm_do_stop+0x50/0x54)
> [ 116.032928] [<c0663be0>] (snd_pcm_do_stop) from [<c06639c4>]
> (snd_pcm_action_single+0x38/0x80)
> [ 116.041961] [<c06639c4>] (snd_pcm_action_single) from [<c066aa4c>]
> (snd_pcm_update_state+0xd0/0x100)
> [ 116.051574] [<c066aa4c>] (snd_pcm_update_state) from [<c066ac20>]
> (snd_pcm_update_hw_ptr0+0x1a4/0x3ac)
> [ 116.061340] [<c066ac20>] (snd_pcm_update_hw_ptr0) from [<c066ae9c>]
> (snd_pcm_period_elapsed+0x74/0xb4)
> [ 116.071136] [<c066ae9c>] (snd_pcm_period_elapsed) from [<c04e63f8>]
> (vchan_complete+0x190/0x1a4)
> [ 116.080352] [<c04e63f8>] (vchan_complete) from [<c013ee68>]
> (tasklet_action+0x88/0x128)
> [ 116.088775] [<c013ee68>] (tasklet_action) from [<c013dee0>]
> (__do_softirq+0xc4/0x55c)
> [ 116.096984] [<c013dee0>] (__do_softirq) from [<c013e6b8>] (irq_exit+0xc0/0x134)
> [ 116.104675] [<c013e6b8>] (irq_exit) from [<c01a17a8>]
> (__handle_domain_irq+0x6c/0xe0)
> [ 116.112884] [<c01a17a8>] (__handle_domain_irq) from [<c07f96b0>]
> (__irq_svc+0x70/0x98)
> [ 116.121215] [<c07f96b0>] (__irq_svc) from [<c0613808>]
> (cpuidle_enter_state+0x15c/0x464)
> [ 116.129699] [<c0613808>] (cpuidle_enter_state) from [<c0187788>]
> (cpu_startup_entry+0x2b8/0x3e0)
> [ 116.138946] [<c0187788>] (cpu_startup_entry) from [<c0b00c1c>]
> (start_kernel+0x340/0x3b4)
>
> There is one more issue: if we have playback and capture running at the same
> time and you stop one of them. It will remove the QoS and the remaining stream
> might break.
it is better to place the QoS in omap_mcbsp_request() and remove it in
omap_mcbsp_free(). This way we retain the QoS for the time the McBSP is in
active use.
>
--
Péter
--
To unsubscribe from this list: send the line "unsubscribe linux-omap" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
