Ticket #2330 (new defect)

Opened 4 years ago

recording from usb headset and playing back audio at the same time prints "frame 0 active: -18"

Reported by: lindi Owned by: openmoko-kernel
Priority: normal Milestone:
Component: kernel Version: unspecified
Severity: normal Keywords:
Cc: Blocked By:
Blocking: Estimated Completion (week):
HasPatchForReview: no PatchReviewResult:
Reproducible: always

Description

Steps to reproduce:
0) connect usb headset to openmoko
1) alsactl restore -f stereoout.state
2) cat /dev/zero | aplay -D hw:0,0 -t raw -r 8000 -f S16_LE -c 2
3) arecord -D hw:1 -t raw -r 48000 -f S16_LE -c 1 > /dev/null
4) Try to run both at the same time

Expected results:
2) audio is played with speaker
3) audio is recorded from usb headset
4) audio is played with speaker and recorded from usb headset

Actual results:
2) seems to work:

Playing raw data 'stdin' : Signed 16 bit Little Endian, Rate 8000 Hz, Stereo

and vmstat shows almost no load:

procs -----------memory---------- ---swap-- -----io---- -system-- ----cpu----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa
 0  0    108  12952  10016  57468    0    0     0     0  326  244  0  1 99  0
 0  0    108  13584  10016  57468    0    0     0     0  323  258  0  1 99  0
 0  0    108  13200  10016  57468    0    0     0     0  344  283  0  2 98  0
 0  0    108  13172  10024  57468    0    0     0     2  313  253  2  2 95  1
 0  0    108  13172  10032  57468    0    0     0     2  311  234  0  0 98  2
 0  0    108  13172  10032  57468    0    0     0     0  310  229  0  1 99  0
 0  0    108  13172  10032  57468    0    0     0     0  319  237  0  1 99  0
 0  0    108  13172  10032  57468    0    0     0     0  348  242  0  1 99  0
 0  0    108  13172  10032  57468    0    0     0     0  311  238  0  1 99  0

3) seems to work

Recording raw data 'stdin' : Signed 16 bit Little Endian, Rate
48000 Hz, Mono

and vmstat again shows almost no load:

procs -----------memory---------- ---swap-- -----io---- -system-- ----cpu----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa

 0  1    108  14148  10084  57472    0    0     0     2 2306  238  0  0 97  3
 0  0    108  14120  10084  57472    0    0     0     0 2307  249  2  2 95  2
 0  0    108  14120  10092  57472    0    0     0     2 2305  246  0  0 98  1
 0  0    108  14120  10092  57472    0    0     0     0 2311  242  0  0 100  0
 0  0    108  14120  10092  57472    0    0     0     0 2308  244  0  0 99  0
 0  0    108  14120  10092  57472    0    0     0     0 2304  240  0  0 100  0

4) causes aplay to print

underrun!!! (at least 5.185 ms long)
underrun!!! (at least 0.015 ms long)
underrun!!! (at least 3.817 ms long)
underrun!!! (at least 1.094 ms long)
underrun!!! (at least 9.648 ms long)
underrun!!! (at least 0.540 ms long)
underrun!!! (at least 0.700 ms long)
underrun!!! (at least 5.194 ms long)
underrun!!! (at least 0.013 ms long)
underrun!!! (at least 0.014 ms long)
underrun!!! (at least 0.715 ms long)
underrun!!! (at least 2.273 ms long)
underrun!!! (at least 7.920 ms long)
underrun!!! (at least 3.670 ms long)
underrun!!! (at least 0.069 ms long)

and kernel to print

[16892.715000] frame 0 active: -18
[16892.725000] frame 0 active: -18
[16892.725000] frame 0 active: -18
[16892.725000] frame 0 active: -18
[16892.725000] frame 0 active: -18
[16892.725000] frame 0 active: -114
[16892.725000] frame 0 active: -18
[16892.725000] frame 0 active: -18
[16892.730000] frame 0 active: -18
[16892.730000] frame 0 active: -114
[16892.730000] frame 0 active: -18
[16892.730000] frame 0 active: -18
[16892.730000] frame 0 active: -18
[16892.730000] frame 0 active: -18
[16892.730000] frame 0 active: -18
[16892.735000] frame 0 active: -18
[16892.735000] frame 0 active: -18
[16892.735000] frame 0 active: -18
[16892.735000] frame 0 active: -18
[16892.735000] frame 0 active: -18
[16892.735000] frame 0 active: -114
[16892.735000] frame 0 active: -18
[16892.740000] frame 0 active: -18
[16892.740000] frame 0 active: -18
[16892.740000] frame 0 active: -114
[16892.740000] frame 0 active: -18
[16892.740000] frame 0 active: -18
[16892.740000] frame 0 active: -18
[16892.740000] frame 0 active: -18
[16892.745000] frame 0 active: -18
[16892.745000] frame 0 active: -18
[16892.745000] frame 0 active: -18
[16892.745000] frame 0 active: -18
[16892.745000] frame 0 active: -18
[16892.745000] frame 0 active: -18
[16892.745000] frame 0 active: -18

at a very rapid rate.

More info:
1) kernel is andy-tracking a3587e4ed77974ad with DEBUG and PREEMPT disabled.

Note: See TracTickets for help on using tickets.