search

openwrt / packages

Community maintained packages for OpenWrt. Documentation for submitting pull requests is in CONTRIBUTING.md
GNU General Public License v2.0
3.96k stars 3.46k forks source link

mpd-full + upmpdcli: out of memory with certain audio files #14467

Open skateskate opened 3 years ago

skateskate commented 3 years ago

Maintainer: @thess @ignisf Environment: Oolite v5.1 board (CPU: QCA9531, RAM: 128 MB), mips24_kc, SNAPSHOT r6712-7e32e86, ar71xx/generic, kernel 4.9.91, Upmpdcli 1.4.6 libupnpp 0.17.2, Music Player Daemon 0.21.25 (0.21.25)

Description: The system goes in "out of memory" when I try to stream certain FLAC files (44,1 kHz 24bit) using upmpdcli + mpd in combination with BubbleUPnP (Android version). If the same audio files are reproduced locally (i.e., using mpc and reading them from an USB stick connected to the board, so not using upmpdcli) everything is fine.

Mpd logs show these messages when the board reaches the out of memory condition:

alsa_output: Underrun on ALSA device "hw:CARD=x20,DEV=0"
alsa_output: Decoder is too slow; playing silence to avoid xrun

When the system is in the out of memory condition, I need to reboot the board since everything is unresponsive. Sometimes is the system to kill MPD, as shown in the following dmesg logs:

[ 3226.622712] hostapd invoked oom-killer: gfp_mask=0x2420848(GFP_NOFS|__GFP_NOFAIL|__GFP_HARDWALL|__GFP_MOVABLE), nodemask=0, order=0, oom_score_adj=0
[ 3226.636662] CPU: 0 PID: 1341 Comm: hostapd Not tainted 4.9.91 #0
[ 3226.642898] Stack : 804f767a 00000034 00000000 00000001 87c99c4c 804792a7 8042942c 0000053d
[ 3226.651644]         804f37c0 ffffffff 00000001 00200000 00000001 800a957c 00000000 00000004
[ 3226.660352]         00000006 8048b2b4 8042ce1c 8692f984 00000000 800d736c 804f767a 00000088
[ 3226.669071]         00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[ 3226.677779]         00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[ 3226.686470]         ...
[ 3226.689026] Call Trace:
[ 3226.691574] [<8006b530>] show_stack+0x70/0x8c
[ 3226.696112] [<80112a70>] dump_header.isra.5+0x80/0x174
[ 3226.701477] [<800dce34>] oom_kill_process+0xac/0x404
[ 3226.706620] [<800dd6d4>] out_of_memory+0x3c4/0x3e8
[ 3226.711599] [<800e0c78>] __alloc_pages_nodemask+0x92c/0x9a8
[ 3226.717362] [<800d92b0>] pagecache_get_page+0x268/0x354
[ 3226.722794] [<801455fc>] __getblk_gfp+0xfc/0x378
[ 3226.727605] [<8017267c>] squashfs_read_data+0x25c/0x6f0
[ 3226.733022] [<801767e0>] squashfs_readpage_block+0x400/0x5d0
[ 3226.738888] [<801743f0>] squashfs_readpage+0x540/0x680
[ 3226.744211] [<800e534c>] __do_page_cache_readahead+0x21c/0x274
[ 3226.750261] [<800db8cc>] filemap_fault+0x2a0/0x5cc
[ 3226.755243] [<800f94cc>] __do_fault+0x68/0x108
[ 3226.759863] [<800fca34>] handle_mm_fault+0x448/0xb2c
[ 3226.765051] [<8007183c>] __do_page_fault+0x23c/0x468
[ 3226.770229] [<80066380>] ret_from_exception+0x0/0x10
[ 3226.775357] Mem-Info:
[ 3226.777749] active_anon:22307 inactive_anon:16 isolated_anon:0
[ 3226.777749]  active_file:313 inactive_file:315 isolated_file:0
[ 3226.777749]  unevictable:0 dirty:0 writeback:0 unstable:0
[ 3226.777749]  slab_reclaimable:198 slab_unreclaimable:1274
[ 3226.777749]  mapped:85 shmem:27 pagetables:89 bounce:0
[ 3226.777749]  free:4094 free_pcp:13 free_cma:0
[ 3226.810729] Node 0 active_anon:89228kB inactive_anon:64kB active_file:1252kB inactive_file:1260kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:340kB dirty:0kB writeback:0kB shmem:108kB writeback_tmp:0kB unstable:0kB pages_scanned:25523 all_unreclaimable? yes
[ 3226.835803] Normal free:16376kB min:16384kB low:20480kB high:24576kB active_anon:89228kB inactive_anon:64kB active_file:1252kB inactive_file:1260kB unevictable:0kB writepending:0kB present:131072kB managed:124880kB mlocked:0kB slab_reclaimable:792kB slab_unreclaimable:5096kB kernel_stack:520kB pagetables:356kB bounce:0kB free_pcp:52kB local_pcp:52kB free_cma:0kB
[ 3226.868907] lowmem_reserve[]: 0 0
[ 3226.872357] Normal: 80*4kB (UME) 93*8kB (UME) 65*16kB (UME) 16*32kB (ME) 27*64kB (UME) 14*128kB (UME) 8*256kB (UME) 2*512kB (ME) 1*1024kB (M) 1*2048kB (E) 1*4096kB (M) = 16376kB
655 total pagecache pages
[ 3226.891376] 0 pages in swap cache
[ 3226.894801] Swap cache stats: add 0, delete 0, find 0/0
[ 3226.900212] Free swap  = 0kB
[ 3226.903188] Total swap = 0kB
[ 3226.906163] 32768 pages RAM
[ 3226.909067] 0 pages HighMem/MovableOnly
[ 3226.913034] 1548 pages reserved
[ 3226.916281] [ pid ]   uid  tgid total_vm      rss nr_ptes nr_pmds swapents oom_score_adj name
[ 3226.925126] [  518]     0   518      296       15       3       0        0             0 ubusd
[ 3226.934053] [  525]     0   525      225       10       3       0        0             0 askfirst
[ 3226.943231] [  783]     0   783      306       27       4       0        0             0 logd
[ 3226.952059] [  858]     0   858      413       46       4       0        0             0 netifd
[ 3226.961068] [  894]     0   894      355       39       3       0        0             0 odhcpd
[ 3226.970074] [  953]     0   953      266       11       3       0        0             0 dropbear
[ 3226.979262] [ 1148]     0  1148      300       11       3       0        0             0 ntpd
[ 3226.988088] [ 1233]    51  1233     2559      116       5       0        0             0 pulseaudio
[ 3226.997460] [ 1341]     0  1341      424       38       4       0        0             0 hostapd
[ 3227.006534] [ 1484]   453  1484      328       34       4       0        0             0 dnsmasq
[ 3227.015644] [ 1509]     0  1509      283       62       3       0        0             0 dropbear
[ 3227.024833] [ 1510]     0  1510      301       11       4       0        0             0 ash
[ 3227.033566] [ 1540]     0  1540      283       26       3       0        0             0 dropbear
[ 3227.042754] [ 1541]     0  1541      301       11       4       0        0             0 ash
[ 3227.051497] [ 1648]     0  1648    25422    21812      28       0        0             0 mpd
[ 3227.060230] [ 1788]    89  1788     1568      156       4       0        0             0 upmpdcli
[ 3227.069417] [ 1804]     0  1804      300       17       3       0        0             0 top
[ 3227.078148] Out of memory: Kill process 1648 (mpd) score 678 or sacrifice child
[ 3227.085741] Killed process 1648 (mpd) total-vm:101688kB, anon-rss:87032kB, file-rss:216kB, shmem-rss:0kB
[ 3228.235104] oom_reaper: reaped process 1648 (mpd), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB

I don't know if it is a problem of mpd or upmpdcli, the strange thing is that, from USB, the files are reproduced correctly.

I am a linux newbe, please forgive me if I have made some mistakes in this issue report.

ignisf commented 3 years ago

Hi could you try to play them from a webserver. I think the command is mpc add http://yourhttpserver.com:port/youfile.flac? You can start a simple http server that shares the working directory by executing python -m http.server 8000.

neheb commented 3 years ago

ping @medoc92

mpd is the one with memory problems it seems. In OpenWrt, it is patched to use libnpupnp.

skateskate commented 3 years ago

Hi could you try to play them from a webserver. I think the command is mpc add http://yourhttpserver.com:port/youfile.flac? You can start a simple http server that shares the working directory by executing python -m http.server 8000.

Using the python server everything works fine.

Edit: on a second listening I noticed that there are some skips in the audio reproduction from the server. MPD shows the following message:

alsa_output: Decoder is too slow; playing silence to avoid xrun
medoc92 commented 3 years ago

This is not related to the npupnp instance in mpd, it is only used when using an UPnP Media Server as a backend, not for normal operation like here. MPD is just using the Curl input plugin to fetch from the Media Server through HTTP. upmpdcli is doing all the UPnP stuff.

The output of "ps aux" before and when the problem occurs would be useful, I don't know how the processes in the above trace are selected.

As someone who began working on a shared computer with 1MB of memory, I shudder to say this, but 128 MB is not a lot these days.

I had a look at the mpd resident size while playing from minimserver, and it's clearly linked to the track size. As far as I can see, it actually buffers the whole track (I see around 80 mb for a 14mn 44/16/2 track)

The strange thing is that you can't reproduce the problem when using mpc to play from a WEB server. The Curl input plugin is used in the same way in both cases (upmpdcli is just another mpd client like mpc, just with a different front-end interface). Maybe try to play a longer track from the WEB server and see what happens.

I would guess that there is a limit to how much mpd will prefetch, but I don't know how it is set.

medoc92 commented 3 years ago

Just ran a few more tests, and the mpd resident size seems to depend on the track size in a weird way: just tried to play a complete CD image, and it stays at 20MB. Go back to playing a 6mn track and it's at 55MB. It would weirdly appear that it has a track size limit beyond which it buffers a fixed size which is much smaller than the limit ?? Maybe there is an explanation in the mpd doc...

skateskate commented 3 years ago

The output of "ps aux" before and when the problem occurs would be useful, I don't know how the processes in the above trace are selected.

Unfortunately I don't have ps aux installed in my system, I hope that the output of top is equally valuable.

System in idle (i.e., nothing reproducing)
==========================================

Mem: 44076K used, 80804K free, 152K shrd, 6832K buff, 20064K cached
CPU:   0% usr   0% sys   0% nic  99% idle   0% io   0% irq   0% sirq
Load average: 0.01 0.27 0.20 1/59 1679
  PID  PPID USER     STAT   VSZ %VSZ %CPU COMMAND
    4     2 root     SW       0   0%   0% [kworker/0:0]
 1679  1667 root     R     1200   1%   0% top
 1544     1 upmpdcli S     6188   5%   0% /usr/bin/upmpdcli -i br-lan
 1666  1514 root     S     1132   1%   0% /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300 -T 3
    8     2 root     SW       0   0%   0% [kworker/u2:1]
 1116     1 root     S<   14456  12%   0% /usr/bin/mpd --no-daemon /etc/mpd.conf
 1605     1 pulse    S<   10236   8%   0% /usr/bin/pulseaudio --system --disallow-exit --disallow-module-loading --disable-shm --exit-idle-time=-1 --realtime=false
 1352     1 root     S     1696   1%   0% /usr/sbin/hostapd -s -P /var/run/wifi-phy0.pid -B /var/run/hostapd-phy0.conf
 1013     1 root     S     1652   1%   0% /sbin/netifd
    1     0 root     S     1540   1%   0% /sbin/procd
 1050     1 root     S     1420   1%   0% /usr/sbin/odhcpd
 1407     1 dnsmasq  S     1312   1%   0% /usr/sbin/dnsmasq -C /var/etc/dnsmasq.conf.cfg01411c -k -x /var/run/dnsmasq/dnsmasq.cfg01411c.pid
  938     1 root     S     1224   1%   0% /sbin/logd -S 64
 1667  1666 root     S     1204   1%   0% -ash
 1580     1 root     S<    1200   1%   0% /usr/sbin/ntpd -n -N -S /usr/sbin/ntpd-hotplug -p 0.openwrt.pool.ntp.org -p 1.openwrt.pool.ntp.org -p 2.openwrt.pool.ntp.org -p 3.openwr
  525     1 root     S     1184   1%   0% /sbin/ubusd
 1514     1 root     S     1064   1%   0% /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300 -T 3
  542     1 root     S      900   1%   0% /sbin/askfirst /usr/libexec/login.sh
  188     2 root     SW       0   0%   0% [spi0]
  122     2 root     SW       0   0%   0% [kworker/0:1]
    3     2 root     SW       0   0%   0% [ksoftirqd/0]
    6     2 root     SW       0   0%   0% [kworker/u2:0]
  423     2 root     SW       0   0%   0% [usb-storage]
  232     2 root     SW<      0   0%   0% [bioset]
  227     2 root     SW<      0   0%   0% [bioset]
  323     2 root     SW<      0   0%   0% [ipv6_addrconf]
  217     2 root     SW<      0   0%   0% [bioset]
  207     2 root     SW<      0   0%   0% [bioset]
  212     2 root     SW<      0   0%   0% [bioset]
  222     2 root     SW<      0   0%   0% [bioset]
  331     2 root     SW<      0   0%   0% [kworker/0:1H]
   92     2 root     SW<      0   0%   0% [kblockd]
   89     2 root     SW<      0   0%   0% [crypto]
   87     2 root     SW<      0   0%   0% [writeback]
   90     2 root     SW<      0   0%   0% [bioset]
    7     2 root     SW<      0   0%   0% [lru-add-drain]
  632     2 root     SW<      0   0%   0% [cfg80211]
  422     2 root     SW<      0   0%   0% [scsi_tmf_0]
 1521     2 root     SWN      0   0%   0% [jffs2_gcd_mtd3]
  428     2 root     SW<      0   0%   0% [bioset]
    2     0 root     SW       0   0%   0% [kthreadd]
    5     2 root     SW<      0   0%   0% [kworker/0:0H]
   36     2 root     SW       0   0%   0% [oom_reaper]
  129     2 root     SW       0   0%   0% [kswapd0]
  421     2 root     SW       0   0%   0% [scsi_eh_0]

FLAC song (6:52 minutes, 83.8 MB) streamed from python web server
================================================================

Mem: 50120K used, 74760K free, 156K shrd, 6832K buff, 20136K cached
CPU:  21% usr  10% sys   0% nic  53% idle   0% io   0% irq  13% sirq
Load average: 0.07 0.10 0.11 1/66 1905
  PID  PPID USER     STAT   VSZ %VSZ %CPU COMMAND
 1887     1 root     S<   19788  16%  31% /usr/bin/mpd --no-daemon /etc/mpd.conf
    3     2 root     SW       0   0%   5% [ksoftirqd/0]
 1544     1 upmpdcli S     6208   5%   1% /usr/bin/upmpdcli -i br-lan
    4     2 root     SW       0   0%   1% [kworker/0:0]
 1679  1667 root     R     1200   1%   1% top
 1666  1514 root     S     1132   1%   0% /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300 -T 3
 1050     1 root     S     1420   1%   0% /usr/sbin/odhcpd
    6     2 root     SW       0   0%   0% [kworker/u2:0]
 1605     1 pulse    S<   10236   8%   0% /usr/bin/pulseaudio --system --disallow-exit --disallow-module-loading --disable-shm --exit-idle-time=-1 --realtime=false
 1352     1 root     S     1696   1%   0% /usr/sbin/hostapd -s -P /var/run/wifi-phy0.pid -B /var/run/hostapd-phy0.conf
 1013     1 root     S     1652   1%   0% /sbin/netifd
    1     0 root     S     1540   1%   0% /sbin/procd
 1407     1 dnsmasq  S     1312   1%   0% /usr/sbin/dnsmasq -C /var/etc/dnsmasq.conf.cfg01411c -k -x /var/run/dnsmasq/dnsmasq.cfg01411c.pid
  938     1 root     S     1224   1%   0% /sbin/logd -S 64
 1681  1680 root     S     1204   1%   0% -ash
 1704  1703 root     S     1204   1%   0% -ash
 1667  1666 root     S     1204   1%   0% -ash
 1580     1 root     S<    1200   1%   0% /usr/sbin/ntpd -n -N -S /usr/sbin/ntpd-hotplug -p 0.openwrt.pool.ntp.org -p 1.openwrt.pool.ntp.org -p 2.openwrt.pool.ntp.org -p 3.openwr
  525     1 root     S     1184   1%   0% /sbin/ubusd
 1680  1514 root     S     1132   1%   0% /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300 -T 3
 1703  1514 root     S     1132   1%   0% /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300 -T 3
 1514     1 root     S     1064   1%   0% /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300 -T 3
  542     1 root     S      900   1%   0% /sbin/askfirst /usr/libexec/login.sh
  188     2 root     SW       0   0%   0% [spi0]
  122     2 root     SW       0   0%   0% [kworker/0:1]
    8     2 root     SW       0   0%   0% [kworker/u2:1]
  423     2 root     SW       0   0%   0% [usb-storage]
  232     2 root     SW<      0   0%   0% [bioset]
  227     2 root     SW<      0   0%   0% [bioset]
  323     2 root     SW<      0   0%   0% [ipv6_addrconf]
  217     2 root     SW<      0   0%   0% [bioset]
  207     2 root     SW<      0   0%   0% [bioset]
  212     2 root     SW<      0   0%   0% [bioset]
  222     2 root     SW<      0   0%   0% [bioset]
  331     2 root     SW<      0   0%   0% [kworker/0:1H]
   92     2 root     SW<      0   0%   0% [kblockd]
  632     2 root     SW<      0   0%   0% [cfg80211]
  422     2 root     SW<      0   0%   0% [scsi_tmf_0]
 1521     2 root     SWN      0   0%   0% [jffs2_gcd_mtd3]
  428     2 root     SW<      0   0%   0% [bioset]
   89     2 root     SW<      0   0%   0% [crypto]
   87     2 root     SW<      0   0%   0% [writeback]
   90     2 root     SW<      0   0%   0% [bioset]
    7     2 root     SW<      0   0%   0% [lru-add-drain]
    2     0 root     SW       0   0%   0% [kthreadd]
    5     2 root     SW<      0   0%   0% [kworker/0:0H]
   36     2 root     SW       0   0%   0% [oom_reaper]
  129     2 root     SW       0   0%   0% [kswapd0]
  421     2 root     SW       0   0%   0% [scsi_eh_0]

Same FLAC song from python server, after 43 seconds playback
=====================================================

Mem: 50968K used, 73912K free, 156K shrd, 6832K buff, 20136K cached
CPU:   7% usr   1% sys   0% nic  87% idle   0% io   0% irq   2% sirq
Load average: 0.22 0.13 0.12 1/66 1906
  PID  PPID USER     STAT   VSZ %VSZ %CPU COMMAND
 1887     1 root     S<   19788  16%   8% /usr/bin/mpd --no-daemon /etc/mpd.conf
 1544     1 upmpdcli S     6208   5%   1% /usr/bin/upmpdcli -i br-lan
 1679  1667 root     R     1200   1%   1% top
 1666  1514 root     S     1132   1%   1% /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300 -T 3
    4     2 root     SW       0   0%   1% [kworker/0:0]
 1703  1514 root     S     1132   1%   0% /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300 -T 3
    3     2 root     SW       0   0%   0% [ksoftirqd/0]
 1704  1703 root     S     1204   1%   0% -ash
 1605     1 pulse    S<   10236   8%   0% /usr/bin/pulseaudio --system --disallow-exit --disallow-module-loading --disable-shm --exit-idle-time=-1 --realtime=false
 1352     1 root     S     1696   1%   0% /usr/sbin/hostapd -s -P /var/run/wifi-phy0.pid -B /var/run/hostapd-phy0.conf
 1013     1 root     S     1652   1%   0% /sbin/netifd
    1     0 root     S     1540   1%   0% /sbin/procd
 1050     1 root     S     1420   1%   0% /usr/sbin/odhcpd
 1407     1 dnsmasq  S     1312   1%   0% /usr/sbin/dnsmasq -C /var/etc/dnsmasq.conf.cfg01411c -k -x /var/run/dnsmasq/dnsmasq.cfg01411c.pid
  938     1 root     S     1224   1%   0% /sbin/logd -S 64
 1681  1680 root     S     1204   1%   0% -ash
 1667  1666 root     S     1204   1%   0% -ash
 1580     1 root     S<    1200   1%   0% /usr/sbin/ntpd -n -N -S /usr/sbin/ntpd-hotplug -p 0.openwrt.pool.ntp.org -p 1.openwrt.pool.ntp.org -p 2.openwrt.pool.ntp.org -p 3.openwr
  525     1 root     S     1184   1%   0% /sbin/ubusd
 1680  1514 root     S     1132   1%   0% /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300 -T 3
 1514     1 root     S     1064   1%   0% /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300 -T 3
  542     1 root     S      900   1%   0% /sbin/askfirst /usr/libexec/login.sh
  188     2 root     SW       0   0%   0% [spi0]
  122     2 root     SW       0   0%   0% [kworker/0:1]
    8     2 root     SW       0   0%   0% [kworker/u2:1]
    6     2 root     SW       0   0%   0% [kworker/u2:0]
  423     2 root     SW       0   0%   0% [usb-storage]
  232     2 root     SW<      0   0%   0% [bioset]
  227     2 root     SW<      0   0%   0% [bioset]
  323     2 root     SW<      0   0%   0% [ipv6_addrconf]
  217     2 root     SW<      0   0%   0% [bioset]
  207     2 root     SW<      0   0%   0% [bioset]
  212     2 root     SW<      0   0%   0% [bioset]
  222     2 root     SW<      0   0%   0% [bioset]
  331     2 root     SW<      0   0%   0% [kworker/0:1H]
   92     2 root     SW<      0   0%   0% [kblockd]
  632     2 root     SW<      0   0%   0% [cfg80211]
  422     2 root     SW<      0   0%   0% [scsi_tmf_0]
 1521     2 root     SWN      0   0%   0% [jffs2_gcd_mtd3]
  428     2 root     SW<      0   0%   0% [bioset]
   89     2 root     SW<      0   0%   0% [crypto]
   87     2 root     SW<      0   0%   0% [writeback]
   90     2 root     SW<      0   0%   0% [bioset]
    7     2 root     SW<      0   0%   0% [lru-add-drain]
    2     0 root     SW       0   0%   0% [kthreadd]
    5     2 root     SW<      0   0%   0% [kworker/0:0H]
   36     2 root     SW       0   0%   0% [oom_reaper]
  129     2 root     SW       0   0%   0% [kswapd0]
  421     2 root     SW       0   0%   0% [scsi_eh_0]

Same FLAC song, streamed from BubbleUpNp to upmpdcli + mpd
==========================================================

Mem: 100420K used, 24460K free, 156K shrd, 2212K buff, 4880K cached
CPU:  18% usr  14% sys   0% nic  35% idle   0% io   0% irq  31% sirq
Load average: 1.95 3.38 1.72 1/67 1974
  PID  PPID USER     STAT   VSZ %VSZ %CPU COMMAND
 1959     1 root     S<     99m  81%  40% /usr/bin/mpd --no-daemon /etc/mpd.conf
    3     2 root     SW       0   0%   8% [ksoftirqd/0]
    4     2 root     SW       0   0%   3% [kworker/0:0]
 1544     1 upmpdcli S     6428   5%   1% /usr/bin/upmpdcli -i br-lan
  129     2 root     SW       0   0%   1% [kswapd0]
 1679  1667 root     R     1200   1%   1% top
 1666  1514 root     S     1132   1%   0% /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300 -T 3
 1013     1 root     S     1652   1%   0% /sbin/netifd
    8     2 root     SW       0   0%   0% [kworker/u2:1]
 1605     1 pulse    S<   10236   8%   0% /usr/bin/pulseaudio --system --disallow-exit --disallow-module-loading --disable-shm --exit-idle-time=-1 --realtime=false
 1352     1 root     S     1696   1%   0% /usr/sbin/hostapd -s -P /var/run/wifi-phy0.pid -B /var/run/hostapd-phy0.conf
    1     0 root     S     1540   1%   0% /sbin/procd
 1050     1 root     S     1420   1%   0% /usr/sbin/odhcpd
 1407     1 dnsmasq  S     1312   1%   0% /usr/sbin/dnsmasq -C /var/etc/dnsmasq.conf.cfg01411c -k -x /var/run/dnsmasq/dnsmasq.cfg01411c.pid
  938     1 root     S     1224   1%   0% /sbin/logd -S 64
  542     1 root     S     1208   1%   0% /bin/ash --login
 1681  1680 root     S     1204   1%   0% -ash
 1667  1666 root     S     1204   1%   0% -ash
 1580     1 root     S<    1200   1%   0% /usr/sbin/ntpd -n -N -S /usr/sbin/ntpd-hotplug -p 0.openwrt.pool.ntp.org -p 1.openwrt.pool.ntp.org -p 2.openwrt.pool.ntp.org -p 3.openwr
  525     1 root     S     1184   1%   0% /sbin/ubusd
 1680  1514 root     S     1132   1%   0% /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300 -T 3
 1514     1 root     S     1064   1%   0% /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300 -T 3
  188     2 root     SW       0   0%   0% [spi0]
  122     2 root     SW       0   0%   0% [kworker/0:1]
    6     2 root     SW       0   0%   0% [kworker/u2:0]
  331     2 root     SW<      0   0%   0% [kworker/0:1H]
  423     2 root     SW       0   0%   0% [usb-storage]
  232     2 root     SW<      0   0%   0% [bioset]
  227     2 root     SW<      0   0%   0% [bioset]
  323     2 root     SW<      0   0%   0% [ipv6_addrconf]
  217     2 root     SW<      0   0%   0% [bioset]
  207     2 root     SW<      0   0%   0% [bioset]
  212     2 root     SW<      0   0%   0% [bioset]
  222     2 root     SW<      0   0%   0% [bioset]
   92     2 root     SW<      0   0%   0% [kblockd]
   89     2 root     SW<      0   0%   0% [crypto]
  632     2 root     SW<      0   0%   0% [cfg80211]
  422     2 root     SW<      0   0%   0% [scsi_tmf_0]
 1521     2 root     SWN      0   0%   0% [jffs2_gcd_mtd3]
  428     2 root     SW<      0   0%   0% [bioset]
   87     2 root     SW<      0   0%   0% [writeback]
   90     2 root     SW<      0   0%   0% [bioset]
    7     2 root     SW<      0   0%   0% [lru-add-drain]
    2     0 root     SW       0   0%   0% [kthreadd]
    5     2 root     SW<      0   0%   0% [kworker/0:0H]
   36     2 root     SW       0   0%   0% [oom_reaper]
  421     2 root     SW       0   0%   0% [scsi_eh_0]

dmesg output after the kill
===========================

[ 2945.145272] upmpdcli invoked oom-killer: gfp_mask=0x24201ca(GFP_HIGHUSER_MOVABLE|__GFP_COLD), nodemask=0, order=0, oom_score_adj=0
[ 2945.157519] CPU: 0 PID: 1640 Comm: upmpdcli Not tainted 4.9.91 #0
[ 2945.163816] Stack : 804f767a 00000035 00000000 00000001 87ccbb3c 804792a7 8042942c 00000668
[ 2945.172558]         804f37c0 ffffffff 00000001 00200000 00000001 800a957c 00000000 00000004
[ 2945.181275]         00000006 8048b2b4 8042ce1c 85d21ba4 00000000 800d736c 804f767a 00000076
[ 2945.189984]         00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[ 2945.198702]         00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[ 2945.207418]         ...
[ 2945.209958] Call Trace:
[ 2945.212500] [<8006b530>] show_stack+0x70/0x8c
[ 2945.217048] [<80112a70>] dump_header.isra.5+0x80/0x174
[ 2945.222402] [<800dce34>] oom_kill_process+0xac/0x404
[ 2945.227554] [<800dd6d4>] out_of_memory+0x3c4/0x3e8
[ 2945.232535] [<800e0c78>] __alloc_pages_nodemask+0x92c/0x9a8
[ 2945.238330] [<800dba30>] filemap_fault+0x404/0x5cc
[ 2945.243306] [<800f94cc>] __do_fault+0x68/0x108
[ 2945.247926] [<800fca34>] handle_mm_fault+0x448/0xb2c
[ 2945.253072] [<8007183c>] __do_page_fault+0x23c/0x468
[ 2945.258246] [<80066380>] ret_from_exception+0x0/0x10
[ 2945.263398] Mem-Info:
[ 2945.265768] active_anon:22280 inactive_anon:15 isolated_anon:0
[ 2945.265768]  active_file:399 inactive_file:481 isolated_file:0
[ 2945.265768]  unevictable:0 dirty:0 writeback:0 unstable:0
[ 2945.265768]  slab_reclaimable:209 slab_unreclaimable:1209
[ 2945.265768]  mapped:94 shmem:39 pagetables:89 bounce:0
[ 2945.265768]  free:4030 free_pcp:3 free_cma:0
[ 2945.298697] Node 0 active_anon:89120kB inactive_anon:60kB active_file:1596kB inactive_file:1924kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:376kB dirty:0kB writeback:0kB shmem:156kB writeback_tmp:0kB unstable:0kB pages_scanned:67141 all_unreclaimable? yes
[ 2945.323771] Normal free:16120kB min:16384kB low:20480kB high:24576kB active_anon:89120kB inactive_anon:60kB active_file:1596kB inactive_file:1924kB unevictable:0kB writepending:0kB present:131072kB managed:124880kB mlocked:0kB slab_reclaimable:836kB slab_unreclaimable:4836kB kernel_stack:512kB pagetables:356kB bounce:0kB free_pcp:12kB local_pcp:12kB free_cma:0kB
[ 2945.356882] lowmem_reserve[]: 0 0
[ 2945.360342] Normal: 104*4kB (UE) 57*8kB (UE) 21*16kB (UME) 10*32kB (UME) 6*64kB (UME) 3*128kB (M) 2*256kB (ME) 2*512kB (UM) 2*1024kB (UM) 1*2048kB (E) 2*4096kB (M) = 16120kB
919 total pagecache pages
[ 2945.378985] 0 pages in swap cache
[ 2945.382418] Swap cache stats: add 0, delete 0, find 0/0
[ 2945.387829] Free swap  = 0kB
[ 2945.390807] Total swap = 0kB
[ 2945.393782] 32768 pages RAM
[ 2945.396671] 0 pages HighMem/MovableOnly
[ 2945.400642] 1548 pages reserved
[ 2945.403889] [ pid ]   uid  tgid total_vm      rss nr_ptes nr_pmds swapents oom_score_adj name
[ 2945.412734] [  525]     0   525      296       16       3       0        0             0 ubusd
[ 2945.421652] [  542]     0   542      302       12       3       0        0             0 ash
[ 2945.430391] [  938]     0   938      306       26       4       0        0             0 logd
[ 2945.439221] [ 1013]     0  1013      413       67       3       0        0             0 netifd
[ 2945.448227] [ 1050]     0  1050      355       49       3       0        0             0 odhcpd
[ 2945.457220] [ 1352]     0  1352      424       47       4       0        0             0 hostapd
[ 2945.466325] [ 1407]   453  1407      328       42       4       0        0             0 dnsmasq
[ 2945.475431] [ 1514]     0  1514      266       11       4       0        0             0 dropbear
[ 2945.484622] [ 1544]    89  1544     1563      168       5       0        0             0 upmpdcli
[ 2945.493810] [ 1580]     0  1580      300       19       3       0        0             0 ntpd
[ 2945.502632] [ 1605]    51  1605     2559      116       7       0        0             0 pulseaudio
[ 2945.512004] [ 1666]     0  1666      283       25       4       0        0             0 dropbear
[ 2945.521193] [ 1667]     0  1667      301       15       4       0        0             0 ash
[ 2945.529932] [ 1680]     0  1680      283       25       4       0        0             0 dropbear
[ 2945.539126] [ 1681]     0  1681      301       12       3       0        0             0 ash
[ 2945.547866] [ 1959]     0  1959    25406    21784      27       0        0             0 mpd
[ 2945.556585] Out of memory: Kill process 1959 (mpd) score 677 or sacrifice child
[ 2945.564197] Killed process 1959 (mpd) total-vm:101624kB, anon-rss:86912kB, file-rss:224kB, shmem-rss:0kB
[ 2946.825536] oom_reaper: reaped process 1959 (mpd), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
medoc92 commented 3 years ago

I am not familiar with this version of top, and I'm not sure of what VSZ exactly measures. In any cases, mpd is changing from 20 to 99 MB, so it's not too hard to guess where the problem comes from. I'm not familiar enough with the mpd code to know how to cap the buffering.

I've done some tests with mpc and a few HTTP servers.

On all of Apache, MinimServer, and the upmpdcli-uprcl Media Server, the mpd process size grows (to the track size it appears, at least up to some limit).

Only with the python http.server does mpd stay at 20MB.

The only difference I can see between the servers is that the ones in the first group all support seeking (by setting Accept-Ranges: bytes), but the python server does not. Maybe this induces a different behaviour inside the mpd curl input module or around it.

I'd take the question to an mpd forum or mailing list, because the mystery clearly resides inside mpd.

vkostas commented 3 years ago

Wouldn't it be better to upgrade to (i.e. build) the latest MPD version (0.22.4) so we can have better support from MPD owner?

neheb commented 3 years ago

Nope. MPD requires C++17 which the build bots do not support.

ReimuNotMoe commented 6 months ago

I have encountered this problem today as well. It appears that the curl plugin is problematic. When playing large FLAC files through network, it will quickly eat all the RAM up.

Temporary solution: Disable the curl plugin and use the ffmpeg plugin for the http:// protocol.

MPD version: Music Player Daemon 0.23.14 (0.23.14)

neheb commented 6 months ago

That's interesting that ffmpeg can be used for http://. In which case, what's the advantage to curl?

ReimuNotMoe commented 6 months ago

That's interesting that ffmpeg can be used for http://. In which case, what's the advantage to curl?

It doesn't OOM

neheb commented 6 months ago

Just read the code. The same function "protocol_is_whitelisted" is used for both curl and ffmpeg. Which means they support the same protocols. The difference in OpenWrt seems to be mpd vs mpd-full.