Changes between Initial Version and Version 2 of Ticket #6156


Ignore:
Timestamp:
Feb 18, 2017, 4:32:40 AM (3 years ago)
Author:
llogan
Comment:

Legend:

Unmodified
Added
Removed
Modified
  • Ticket #6156

    • Property Keywords alsa added; ALSA removed
    • Property Version changed from unspecified to git-master
    • Property Component changed from avcodec to undetermined
  • Ticket #6156 – Description

    initial v2  
    11I am on a Raspberry Pi Zero with a Pi Camera and an I2S MEMS mic, running the latest Raspbian Jessie. I am attempting to livestream audio and video. I've discovered that when I record ALSA audio with FFMPEG, that process takes 95% of my CPU and produces stuttering, unusable audio in the stream.
    22
    3 I have compiled FFMPEG with ALSA following this: http://vpaste.net/cXV9F
    4 
    53I isolated the issue to the following:
    64
    7 1. ffmpeg -f alsa -acodec pcm_s32le -i mic_sv temp.wav
     51. `ffmpeg -f alsa -acodec pcm_s32le -i mic_sv temp.wav`
    86This single command takes 95% of my CPU.
    97
    10 2. arecord -Dmic_sv -c2 -r48000 -fS32_LE -twav temp.wav
     82. `arecord -Dmic_sv -c2 -r48000 -fS32_LE -twav temp.wav`
    119This single command takes <5% of my CPU.
    1210
    1311I have added a custom hook to ffmpeg so we can see the PCM settings. I have ensured that settings (buffer size, period size, etc.) are identical between the two commands.
    1412
    15 Here is the full console output of FFMPEG: http://vpaste.net/2M5gk
    16 Here is the console output of Arecord:  http://vpaste.net/CPk3A
    17 
    18 After a long chat in the FFMPEG IRC channel, we believe there may be a bug in the way FFMPEG waits for ALSA packets. Arecord uses snd_pcm_wait() to wait for packets, and this command is not used in FFMPEG sources. Inserting '-re' before -i into my FFMPEG command reduces CPU usage to <5%, but is not the right approach, and causes other problems (bitrate is almost 0kbps, audio file generated is <5 kilobytes).
     13Here is the full console output of FFMPEG:
     14
     15{{{
     16$ ALSA_CONFIG_PATH=/usr/share/alsa/alsa.conf:./dumpasoundrc  /home/pi/special/ffmpeg/ffmpeg -v 9 -loglevel 99  -f alsa -acodec pcm_s32le -i michooks -f  null -
     17ffmpeg version git-2017-02-05-e57fd92 Copyright (c) 2000-2017 the FFmpeg developers
     18  built with gcc 4.9.2 (Raspbian 4.9.2-10)
     19  configuration: --extra-cflags=-I/opt/vc/include/IL --enable-nonfree --enable-omx-rpi --logfile=CONFIG.TXT
     20  libavutil      55. 46.100 / 55. 46.100
     21  libavcodec     57. 75.100 / 57. 75.100
     22  libavformat    57. 66.101 / 57. 66.101
     23  libavdevice    57.  2.100 / 57.  2.100
     24  libavfilter     6. 73.100 /  6. 73.100
     25  libswscale      4.  3.101 /  4.  3.101
     26  libswresample   2.  4.100 /  2.  4.100
     27Splitting the commandline.
     28Reading option '-v' ... matched as option 'v' (set logging level) with argument '9'.
     29Reading option '-loglevel' ... matched as option 'loglevel' (set logging level) with argument '99'.
     30Reading option '-f' ... matched as option 'f' (force format) with argument 'alsa'.
     31Reading option '-acodec' ... matched as option 'acodec' (force audio codec ('copy' to copy stream)) with argument 'pcm_s32le'.
     32Reading option '-i' ... matched as input url with argument 'michooks'.
     33Reading option '-f' ... matched as option 'f' (force format) with argument 'null'.
     34Reading option '-' ... matched as output url.
     35Finished splitting the commandline.
     36Parsing a group of options: global .
     37Applying option v (set logging level) with argument 9.
     38Successfully parsed a group of options.
     39Parsing a group of options: input url michooks.
     40Applying option f (force format) with argument alsa.
     41Applying option acodec (force audio codec ('copy' to copy stream)) with argument pcm_s32le.
     42Successfully parsed a group of options.
     43Opening an input file: michooks.
     44[ALSA Debug Hook] Installing hooks.
     45Hooks PCM
     46Slave: Soft volume PCM
     47Control: Boost Capture Volume
     48min_dB: -3
     49max_dB: 50
     50resolution: 256
     51Slave: Route conversion PCM
     52  Transformation table:
     53    0 <- 0
     54    1 <- 0
     55Slave: Mmap emulation PCM
     56Slave: Hardware PCM card 1 'mems-mic' device 0 subdevice 0
     57[ALSA Debug Hook] hw_params:
     58Hooks PCM
     59Slave: Soft volume PCM
     60Control: Boost Capture Volume
     61min_dB: -3
     62max_dB: 50
     63resolution: 256
     64Its setup is:
     65  stream       : CAPTURE
     66  access       : RW_INTERLEAVED
     67  format       : S32_LE
     68  subformat    : STD
     69  channels     : 2
     70  rate         : 48000
     71  exact rate   : 48000 (48000/1)
     72  msbits       : 32
     73  buffer_size  : 65536
     74  period_size  : 16384
     75  period_time  : 341333
     76  tstamp_mode  : NONE
     77  period_step  : 1
     78  avail_min    : 16384
     79  period_event : 0
     80  start_threshold  : 1
     81  stop_threshold   : 65536
     82  silence_threshold: 0
     83  silence_size : 0
     84  boundary     : 1073741824
     85Slave: Route conversion PCM
     86  Transformation table:
     87    0 <- 0
     88    1 <- 0
     89Its setup is:
     90  stream       : CAPTURE
     91  access       : MMAP_INTERLEAVED
     92  format       : S32_LE
     93  subformat    : STD
     94  channels     : 2
     95  rate         : 48000
     96  exact rate   : 48000 (48000/1)
     97  msbits       : 32
     98  buffer_size  : 65536
     99  period_size  : 16384
     100  period_time  : 341333
     101  tstamp_mode  : NONE
     102  period_step  : 1
     103  avail_min    : 16384
     104  period_event : 0
     105  start_threshold  : 1
     106  stop_threshold   : 65536
     107  silence_threshold: 0
     108  silence_size : 0
     109  boundary     : 1073741824
     110Slave: Mmap emulation PCM
     111Its setup is:
     112  stream       : CAPTURE
     113  access       : MMAP_INTERLEAVED
     114  format       : S32_LE
     115  subformat    : STD
     116  channels     : 2
     117  rate         : 48000
     118  exact rate   : 48000 (48000/1)
     119  msbits       : 32
     120  buffer_size  : 65536
     121  period_size  : 16384
     122  period_time  : 341333
     123  tstamp_mode  : NONE
     124  period_step  : 1
     125  avail_min    : 16384
     126  period_event : 0
     127  start_threshold  : 1
     128  stop_threshold   : 65536
     129  silence_threshold: 0
     130  silence_size : 0
     131  boundary     : 1073741824
     132Slave: Hardware PCM card 1 'mems-mic' device 0 subdevice 0
     133Its setup is:
     134  stream       : CAPTURE
     135  access       : RW_INTERLEAVED
     136  format       : S32_LE
     137  subformat    : STD
     138  channels     : 2
     139  rate         : 48000
     140  exact rate   : 48000 (48000/1)
     141  msbits       : 32
     142  buffer_size  : 65536
     143  period_size  : 16384
     144  period_time  : 341333
     145  tstamp_mode  : NONE
     146  period_step  : 1
     147  avail_min    : 16384
     148  period_event : 0
     149  start_threshold  : 1073741824
     150  stop_threshold   : 65536
     151  silence_threshold: 0
     152  silence_size : 0
     153  boundary     : 1073741824
     154  appl_ptr     : 0
     155  hw_ptr       : 0
     156[alsa @ 0x31ea450] All info found
     157[alsa @ 0x31ea450] stream 0: start_time: 1487382765.290 duration: -9223372036854.775
     158[alsa @ 0x31ea450] format: start_time: 1487382765.290 duration: -9223372036854.775 bitrate=3072 kb/s
     159Guessed Channel Layout for Input Stream #0.0 : stereo
     160Input #0, alsa, from 'michooks':
     161  Duration: N/A, start: 1487382765.289814, bitrate: 3072 kb/s
     162    Stream #0:0, 1, 1/1000000: Audio: pcm_s32le, 48000 Hz, stereo, s32, 3072 kb/s
     163Successfully opened the file.
     164Parsing a group of options: output url -.
     165Applying option f (force format) with argument null.
     166Successfully parsed a group of options.
     167Opening an output file: -.
     168Successfully opened the file.
     169detected 1 logical cores
     170[graph_0_in_0_0 @ 0x31f9310] Setting 'time_base' to value '1/48000'
     171[graph_0_in_0_0 @ 0x31f9310] Setting 'sample_rate' to value '48000'
     172[graph_0_in_0_0 @ 0x31f9310] Setting 'sample_fmt' to value 's32'
     173[graph_0_in_0_0 @ 0x31f9310] Setting 'channel_layout' to value '0x3'
     174[graph_0_in_0_0 @ 0x31f9310] tb:1/48000 samplefmt:s32 samplerate:48000 chlayout:0x3
     175[format_out_0_0 @ 0x31f9f10] Setting 'sample_fmts' to value 's16'
     176[format_out_0_0 @ 0x31f9f10] auto-inserting filter 'auto_resampler_0' between the filter 'Parsed_anull_0' and the filter 'format_out_0_0'
     177[AVFilterGraph @ 0x31f9980] query_formats: 4 queried, 6 merged, 3 already done, 0 delayed
     178[auto_resampler_0 @ 0x31faf10] [SWR @ 0x321e130] Using fltp internally between filters
     179[auto_resampler_0 @ 0x31faf10] ch:2 chl:stereo fmt:s32 r:48000Hz -> ch:2 chl:stereo fmt:s16 r:48000Hz
     180Output #0, null, to 'pipe:':
     181  Metadata:
     182    encoder         : Lavf57.66.101
     183    Stream #0:0, 0, 1/48000: Audio: pcm_s16le, 48000 Hz, stereo, s16, 1536 kb/s
     184    Metadata:
     185      encoder         : Lavc57.75.100 pcm_s16le
     186Stream mapping:
     187  Stream #0:0 -> #0:0 (pcm_s32le (native) -> pcm_s16le (native))
     188Press [q] to stop, [?] for help
     189cur_dts is invalid (this is harmless if it occurs once at the start per stream)
     190size=N/A time=00:00:17.84 bitrate=N/A speed=   1x
     191video:0kB audio:3345kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: unknown
     192Input file #0 (michooks):
     193  Input stream #0:0 (audio): 26372 packets read (6851424 bytes); 26372 frames decoded (856428 samples);
     194  Total: 26372 packets (6851424 bytes) demuxed
     195Output file #0 (pipe:):
     196  Output stream #0:0 (audio): 26372 frames encoded (856428 samples); 26372 packets muxed (3425712 bytes);
     197  Total: 26372 packets (3425712 bytes) muxed
     19826372 frames successfully decoded, 0 decoding errors
     199Exiting normally, received signal 2.
     200}}}
     201
     202Here is the console output of Arecord:
     203
     204
     205{{{
     206$ arecord -v -r48000 -c2 -fS32_LE --period-size=16384 --buffer-size=65536 -Dmic_sv -twav /dev/null
     207Recording WAVE '/dev/null' : Signed 32 bit Little Endian, Rate 48000 Hz, Stereo
     208Soft volume PCM
     209Control: Boost Capture Volume
     210min_dB: -3
     211max_dB: 50
     212resolution: 256
     213Its setup is:
     214  stream       : CAPTURE
     215  access       : RW_INTERLEAVED
     216  format       : S32_LE
     217  subformat    : STD
     218  channels     : 2
     219  rate         : 48000
     220  exact rate   : 48000 (48000/1)
     221  msbits       : 32
     222  buffer_size  : 65536
     223  period_size  : 16384
     224  period_time  : 341333
     225  tstamp_mode  : NONE
     226  period_step  : 1
     227  avail_min    : 16384
     228  period_event : 0
     229  start_threshold  : 1
     230  stop_threshold   : 65536
     231  silence_threshold: 0
     232  silence_size : 0
     233  boundary     : 1073741824
     234Slave: Route conversion PCM
     235  Transformation table:
     236    0 <- 0
     237    1 <- 0
     238Its setup is:
     239  stream       : CAPTURE
     240  access       : MMAP_INTERLEAVED
     241  format       : S32_LE
     242  subformat    : STD
     243  channels     : 2
     244  rate         : 48000
     245  exact rate   : 48000 (48000/1)
     246  msbits       : 32
     247  buffer_size  : 65536
     248  period_size  : 16384
     249  period_time  : 341333
     250  tstamp_mode  : NONE
     251  period_step  : 1
     252  avail_min    : 16384
     253  period_event : 0
     254  start_threshold  : 1
     255  stop_threshold   : 65536
     256  silence_threshold: 0
     257  silence_size : 0
     258  boundary     : 1073741824
     259Slave: Mmap emulation PCM
     260Its setup is:
     261  stream       : CAPTURE
     262  access       : MMAP_INTERLEAVED
     263  format       : S32_LE
     264  subformat    : STD
     265  channels     : 2
     266  rate         : 48000
     267  exact rate   : 48000 (48000/1)
     268  msbits       : 32
     269  buffer_size  : 65536
     270  period_size  : 16384
     271  period_time  : 341333
     272  tstamp_mode  : NONE
     273  period_step  : 1
     274  avail_min    : 16384
     275  period_event : 0
     276  start_threshold  : 1
     277  stop_threshold   : 65536
     278  silence_threshold: 0
     279  silence_size : 0
     280  boundary     : 1073741824
     281Slave: Hardware PCM card 1 'mems-mic' device 0 subdevice 0
     282Its setup is:
     283  stream       : CAPTURE
     284  access       : RW_INTERLEAVED
     285  format       : S32_LE
     286  subformat    : STD
     287  channels     : 2
     288  rate         : 48000
     289  exact rate   : 48000 (48000/1)
     290  msbits       : 32
     291  buffer_size  : 65536
     292  period_size  : 16384
     293  period_time  : 341333
     294  tstamp_mode  : NONE
     295  period_step  : 1
     296  avail_min    : 16384
     297  period_event : 0
     298  start_threshold  : 1073741824
     299  stop_threshold   : 65536
     300  silence_threshold: 0
     301  silence_size : 0
     302  boundary     : 1073741824
     303  appl_ptr     : 0
     304  hw_ptr       : 0
     305^CAborted by signal Interrupt...
     306}}}
     307
     308After a long chat in the FFMPEG IRC channel, we believe there may be a bug in the way FFMPEG waits for ALSA packets. Arecord uses `snd_pcm_wait()` to wait for packets, and this command is not used in FFMPEG sources. Inserting `-re` before `-i` into my FFMPEG command reduces CPU usage to <5%, but is not the right approach, and causes other problems (bitrate is almost 0kbps, audio file generated is <5 kilobytes).