Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

USB3 disk writes trigger OOM reaper on Pi 4 #3210

Open
rowanalex123 opened this issue Sep 6, 2019 · 106 comments
Open

USB3 disk writes trigger OOM reaper on Pi 4 #3210

rowanalex123 opened this issue Sep 6, 2019 · 106 comments

Comments

@rowanalex123
Copy link

rowanalex123 commented Sep 6, 2019

Describe the bug
Writing to a USB3 SSD disk results in kernel out of memory reaper killing random processes

To reproduce
Boot Pi 4 from SATAII SSD HDD on USB3 with quirks mode enabled
Run sudo dd if=/dev/zero of=~/test.tmp bs=500K count=8024
Run dmesg

Expected behaviour
No processes killed due to OOM reaper

Actual behaviour

Bunch of core system processes are killed by the OOM reaper.

dmesg output

[222125.725243] Mem-Info:
[222125.725255] active_anon:8353 inactive_anon:8505 isolated_anon:0
                 active_file:18133 inactive_file:179255 isolated_file:84
                 unevictable:20 dirty:5438 writeback:393 unstable:0
                 slab_reclaimable:11578 slab_unreclaimable:12597
                 mapped:8368 shmem:8196 pagetables:698 bounce:0
                 free:605316 free_pcp:475 free_cma:47644
[222125.725262] Node 0 active_anon:33412kB inactive_anon:34020kB active_file:72532kB inactive_file:717020kB unevictable:80kB isolated(anon):0kB isolated(file):336kB mapped:33472kB dirty:21752kB writeback:1572kB shmem:32784kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
[222125.725272] DMA free:210020kB min:16384kB low:20480kB high:24576kB active_anon:0kB inactive_anon:0kB active_file:716kB inactive_file:244kB unevictable:0kB writepending:0kB present:434176kB managed:388116kB mlocked:0kB kernel_stack:1744kB pagetables:0kB bounce:0kB free_pcp:72kB local_pcp:0kB free_cma:190576kB
[222125.725276] lowmem_reserve[]: 0 0 3008 3008
[222125.725300] HighMem free:2211244kB min:512kB low:33016kB high:65520kB active_anon:33868kB inactive_anon:34788kB active_file:72316kB inactive_file:716976kB unevictable:80kB writepending:22908kB present:3080192kB managed:3080192kB mlocked:80kB kernel_stack:0kB pagetables:2792kB bounce:0kB free_pcp:1816kB local_pcp:252kB free_cma:0kB
[222125.725304] lowmem_reserve[]: 0 0 0 0
[222125.725323] DMA: 594*4kB (UHC) 583*8kB (UC) 315*16kB (UEHC) 148*32kB (UHC) 52*64kB (UEHC) 25*128kB (UEHC) 10*256kB (C) 6*512kB (C) 3*1024kB (C) 3*2048kB (C) 42*4096kB (C) = 210224kB
[222125.725408] HighMem: 1113*4kB (UM) 4974*8kB (UM) 5790*16kB (UM) 2307*32kB (UM) 240*64kB (UM) 10*128kB (UM) 1*256kB (M) 1*512kB (M) 85*1024kB (M) 48*2048kB (UM) 439*4096kB (M) = 2211604kB
[222125.725491] 205652 total pagecache pages
[222125.725503] 135 pages in swap cache
[222125.725507] Swap cache stats: add 609, delete 474, find 58/90
[222125.725511] Free swap  = 6954484kB
[222125.725515] Total swap = 6957052kB
[222125.725518] 878592 pages RAM
[222125.725522] 770048 pages HighMem/MovableOnly
[222125.725526] 11515 pages reserved
[222125.725529] 65536 pages cma reserved
[222125.725533] Tasks state (memory values in pages):
[222125.725537] [  pid  ]   uid  tgid total_vm      rss pgtables_bytes swapents oom_score_adj name
[222125.725556] [    238]     0   238     4606      947    49152        1         -1000 systemd-udevd
[222125.725564] [    385]   100   385     5592     1327    57344        3             0 systemd-timesyn
[222125.725569] [    423]     0   423     1986      564    45056        1             0 cron
[222125.725575] [    425]     0   425     3276     1443    53248        0             0 systemd-logind
[222125.725580] [    431] 65534   431     1080      544    32768        4             0 thd
[222125.725586] [    440]   104   440     1715      968    36864        4          -900 dbus-daemon
[222125.725591] [    447]     0   447     2675     1012    45056        2             0 wpa_supplicant
[222125.725597] [    449]     0   449      923      175    28672        4             0 alsactl
[222125.725603] [    450]     0   450     6914       17    40960        3             0 rngd
[222125.725608] [    454]     0   454     6378     1004    53248        0             0 rsyslogd
[222125.725614] [    461]   108   461     1475      750    40960        0             0 avahi-daemon
[222125.725619] [    480]   108   480     1443       60    36864        3             0 avahi-daemon
[222125.725625] [    495]     0   495      740      502    28672       10             0 dhcpcd
[222125.725632] [    516]     0   516     2094      669    36864        2             0 vncserver-x11-s
[222125.725637] [    555]     0   555    10035     1802    73728        0             0 lightdm
[222125.725642] [    564]     0   564     2699     1400    45056        0         -1000 sshd
[222125.725647] [    565]     0   565    11426     2116    81920        3             0 polkitd
[222125.725652] [    576]     0   576     2740      813    45056        0             0 wpa_supplicant
[222125.725658] [    598]     0   598     1431      631    40960       10             0 login
[222125.725663] [    736]  1000   736     3699     1863    53248        0             0 systemd
[222125.725668] [    740]  1000   740     4231      424    61440       28             0 (sd-pam)
[222125.725674] [    768]  1000   768     1668      870    40960        0             0 dbus-daemon
[222125.725679] [    817]  1000   817    13157     1476    69632        0             0 gvfsd
[222125.725684] [    822]  1000   822    14192     1669    81920        0             0 gvfsd-fuse
[222125.725690] [    937]  1000   937    14005     1720    86016        0             0 gvfs-afc-volume
[222125.725695] [    946]  1000   946    10025     1264    69632        0             0 gvfs-goa-volume
[222125.725700] [    954]  1000   954    10031     1120    61440        0             0 gvfs-mtp-volume
[222125.725706] [    966]  1000   966    10423     1219    69632        0             0 gvfs-gphoto2-vo
[222125.725711] [   1045]  1000  1045    10895     1604    77824        0             0 gnome-keyring-d
[222125.725717] [   1085]  1000  1085     7775     1225    65536        0             0 gvfsd-metadata
[222125.725722] [   1115]  1000  1115     2601     1018    45056        1             0 zsh
[222125.725727] [   1155]     0  1155      535       31    28672        1             0 hciattach
[222125.725733] [   1159]     0  1159     2452     1142    40960        0             0 bluetoothd
[222125.725739] [   1163]     0  1163     6676     1000    57344        3             0 bluealsa
[222125.725748] [   4614]     0  4614     2701     1417    45056        0             0 sshd
[222125.725754] [   4617]  1000  4617     2701      931    45056        0             0 sshd
[222125.725760] [   4619]  1000  4619     2632     1125    49152        0             0 zsh
[222125.725766] [   4732]     0  4732     2701     1416    45056        0             0 sshd
[222125.725772] [   4736]  1000  4736     2701      905    40960        0             0 sshd
[222125.725778] [   4738]  1000  4738     2632     1079    45056        0             0 zsh
[222125.725783] [   4793]  1000  4793     2154      918    40960        0             0 bash
[222125.725790] [   4954]     0  4954     8141     2001    65536        0             0 lightdm
[222125.725796] [   5114]  1000  5114    27034     2664   126976        0             0 gvfs-udisks2-vo
[222125.725804] [   5162]  1000  5162    13806     2009    90112        0             0 gvfsd-trash
[222125.725810] [   5366]  1000  5366    16127     1987    90112        0             0 gvfsd-network
[222125.725815] [   5402]  1000  5402    13564     1625    77824        0             0 gvfsd-dnssd
[222125.725879] [   6277]     0  6277     2514      815    53248        0             0 sudo
[222125.725885] [   6282]     0  6282     2355      674    40960        0             0 slabtop
[222125.725890] [   6295]  1000  6295     1751      459    40960        0             0 dd
[222125.725896] Out of memory: Kill process 5114 (gvfs-udisks2-vo) score 1 or sacrifice child
[222125.725917] Killed process 5114 (gvfs-udisks2-vo) total-vm:108136kB, anon-rss:1296kB, file-rss:9360kB, shmem-rss:0kB
**[222125.729422] oom_reaper: reaped process 5114 (gvfs-udisks2-vo), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB**
[222126.015293] systemd[1]: Starting Journal Service...
[222126.021366] systemd[1]: fail2ban.service: Main process exited, code=killed, status=9/KILL
[222126.021730] systemd[1]: fail2ban.service: Failed with result 'signal'.
[222126.243642] systemd-journald[6309]: File /run/log/journal/d5d73d639cf747f6a9c246e71e2e9554/system.journal corrupted or uncleanly shut down, renaming and replacing.

slabtop output

 Active / Total Objects (% used)    : 635208 / 659018 (96.4%)
 Active / Total Slabs (% used)      : 15395 / 15395 (100.0%)
 Active / Total Caches (% used)     : 89 / 111 (80.2%)
 Active / Total Size (% used)       : 88160.57K / 93933.56K (93.9%)
 Minimum / Average / Maximum Object : 0.02K / 0.14K / 8.00K

  OBJS ACTIVE  USE OBJ SIZE  SLABS OBJ/SLAB CACHE SIZE NAME
231680 230343  99%    0.06K   3620       64     14480K buffer_head
 59456  54537  91%    0.06K    929       64      3716K kmalloc-64
 52736  52736 100%    0.03K    412      128      1648K anon_vma_chain
 44730  36236  81%    0.13K   1491       30      5964K dentry
 29610  29610 100%    0.09K    705       42      2820K kernfs_node_cache
 27729  27029  97%    0.10K    711       39      2844K vm_area_struct
 26937  26937 100%    0.05K    369       73      1476K anon_vma
 21735  21012  96%    0.19K   1035       21      4140K filp
 15876  15876 100%    0.11K    441       36      1764K ext4_groupinfo_4k
 17900  14718  82%    0.71K   1132       22     18112K ext4_inode_cache
 12614  12204  96%    0.38K    608       21      4864K inode_cache
 12974  10711  82%    0.30K    499       26      3992K radix_tree_node
  9010   9010 100%    0.02K     53      170       212K pde_opener
  7424   7424 100%    0.03K     58      128       232K ext4_extent_status
  6112   6050  98%    0.12K    191       32       764K cred_jar
  5984   5712  95%    0.12K    187       32       748K kmalloc-128
  5508   5508 100%    0.04K     54      102       216K eventpoll_pwq
  4928   4865  98%    0.06K     77       64       308K pid
  4864   4864 100%    0.03K     38      128       152K ftrace_event_field
  4620   4536  98%    0.19K    220       21       880K skbuff_head_cache
  4944   4515  91%    0.50K    310       16      2480K kmalloc-512
  4094   4094 100%    0.09K     89       46       356K seq_file
  4091   3924  95%    0.41K    219       19      1752K proc_inode_cache
  2880   2880 100%    0.06K     45       64       180K kmem_cache_node
  2720   2720 100%    0.05K     32       85       128K inotify_inode_mark
  2709   2709 100%    0.19K    129       21       516K kmem_cache
  2448   2448 100%    0.25K    153       16       612K kmalloc-256
  2808   2407  85%    0.42K    157       18      1256K shmem_inode_cache
  2496   2334  93%    1.00K    156       16      2496K kmalloc-1024
  1895   1895 100%    0.75K     91       21      1456K UNIX
  1701   1652  97%    0.44K     95       18       760K sock_inode_cache
  1587   1587 100%    0.69K     69       23      1104K signal_cache
  1536   1536 100%    1.31K     64       24      2048K sighand_cache
  1326   1326 100%    0.04K     13      102        52K jbd2_inode
  1281   1281 100%    0.19K     61       21       244K kmalloc-192
  1275   1275 100%    0.05K     15       85        60K trace_event_file
  1152   1152 100%    0.06K     18       64        72K jbd2_journal_head
  1104   1104 100%    0.50K     69       16       552K mm_struct
  1129   1097  97%    3.75K    142        8      4544K task_struct
  1024   1024 100%    0.02K      4      256        16K fsnotify_mark_connector
   960    960 100%    0.25K     60       16       240K files_cache
   928    897  96%    2.00K     58       16      1856K kmalloc-2048
   882    882 100%    0.19K     42       21       168K biovec-16
   842    842 100%    4.00K    107        8      3424K kmalloc-4096
   736    723  98%    0.25K     46       16       184K task_group
   704    704 100%    0.06K     11       64        44K blkdev_ioc
   703    703 100%    0.81K     37       19       592K UDP`

System

System Information
------------------

Raspberry Pi 4 Model B Rev 1.1
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"

Raspberry Pi reference 2019-07-10
Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, 175dfb027ffabd4b8d5080097af0e51ed9a4a56c, stage5

Linux mbox 4.19.66-v7l+ #1253 SMP Thu Aug 15 12:02:08 BST 2019 armv7l GNU/Linux
Hardware	: BCM2835
Revision	: c03111
Serial		: 100000003f3b5427
Throttled flag  : throttled=0x0
Camera          : supported=0 detected=0

Videocore information
---------------------

Aug 15 2019 12:03:51
Copyright (c) 2012 Broadcom
version 9f8431fb7839c7f00f52b81f5822ddab2b31d0db (clean) (release) (start)

alloc failures:     0
compactions:        0
legacy block fails: 0

Filesystem information
----------------------
Filesystem      1K-blocks       Used Available Use% Mounted on
/dev/root       114854492   20116484  88860636  19% /
devtmpfs          1602056          0   1602056   0% /dev
tmpfs             1734152          0   1734152   0% /dev/shm
tmpfs             1734152      18084   1716068   2% /run
tmpfs                5120          4      5116   1% /run/lock
tmpfs             1734152          0   1734152   0% /sys/fs/cgroup
/dev/mmcblk0p1     258096      40982    217114  16% /boot
tmpfs              346828          0    346828   0% /run/user/1000
/dev/mmcblk0p2    7347920    6085992    884776  88% /media/pi/rootfs
/dev/dm-0      1922695992 1787748528  37257148  98% /media/pi/2tb_luks_ind
tmpfs              346828          0    346828   0% /run/user/109

Filename				Type		Size	Used	Priority
/var/swap                               file		6957052	17152	-2

Package version information
---------------------------
raspberrypi-ui-mods:
  Installed: 1.20190717
raspberrypi-sys-mods:
  Installed: 20190730
openbox:
  Installed: 3.6.1-8+rpt2
lxpanel:
  Installed: 0.10.0-2+rpt6
pcmanfm:
  Installed: 1.3.1-1+rpt8
rpd-plym-splash:
  Installed: 0.19

Networking Information
----------------------

docker0: flags=4099<UP,BROADCAST,MULTICAST>  mtu 1500
        inet x.x.x.x  netmask x.x.x.x  broadcast x.x.x.x
        ether m.m.m.m  txqueuelen 0  (Ethernet)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 0  bytes 0 (0.0 B)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

eth0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet x.x.x.x  netmask x.x.x.x  broadcast x.x.x.x
        ether m.m.m.m  txqueuelen 1000  (Ethernet)
        RX packets 139915  bytes 11835558 (11.2 MiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 144225  bytes 39066373 (37.2 MiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

lo: flags=73<UP,LOOPBACK,RUNNING>  mtu 65536
        inet x.x.x.x  netmask x.x.x.x
        loop  txqueuelen 1000  (Local Loopback)
        RX packets 408  bytes 31629 (30.8 KiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 408  bytes 31629 (30.8 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0


USB Information
---------------

/:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=dwc_otg/1p, 480M
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 5000M
    |__ Port 1: Dev 2, If 0, Class=Mass Storage, Driver=usb-storage, 5000M
    |__ Port 2: Dev 3, If 0, Class=Mass Storage, Driver=usb-storage, 5000M
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/1p, 480M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M

config.txt
----------

arm_freq=1500
audio_pwm_mode=514
config_hdmi_boost=5
core_freq=500
core_freq_min=250
disable_commandline_tags=2
disable_l2cache=1
display_hdmi_rotate=-1
display_lcd_rotate=-1
enable_gic=1
force_eeprom_read=1
force_pwm_open=1
framebuffer_ignore_alpha=1
framebuffer_swap=1
gpu_freq=500
gpu_freq_min=500
init_uart_clock=0x2dc6c00
lcd_framerate=60
mask_gpu_interrupt0=1024
mask_gpu_interrupt1=0x10000
max_framebuffers=2
pause_burst_frames=1
program_serial_random=1
hdmi_force_cec_address:0=65535
hdmi_force_cec_address:1=65535
hdmi_pixel_freq_limit:0=0x11e1a300
hdmi_pixel_freq_limit:1=0x11e1a300
device_tree=-
hdmi_cvt:0=
hdmi_cvt:1=
hdmi_edid_filename:0=
hdmi_edid_filename:1=
hdmi_timings:0=
hdmi_timings:1=

cmdline.txt
-----------
coherent_pool=1M 8250.nr_uarts=0 cma=64M cma=256M video=HDMI-A-1:1920x1080@60 smsc95xx.macaddr=DC:A6:32:07:A4:17 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  fsck.mode=force usb-storage.quirks=152d:0578:u,1058:1140:u dwc_otg.lpm_enable=0 console=ttyS0,115200 console=tty1 root=PARTUUID=698e33bd-01 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait ipv6.disable=1

raspi-gpio settings
-------------------

BANK0 (GPIO 0 to 27):
GPIO 0: level=1 fsel=0 func=INPUT pull=UP
GPIO 1: level=1 fsel=0 func=INPUT pull=UP
GPIO 2: level=1 fsel=0 func=INPUT pull=UP
GPIO 3: level=1 fsel=0 func=INPUT pull=UP
GPIO 4: level=1 fsel=0 func=INPUT pull=UP
GPIO 5: level=1 fsel=0 func=INPUT pull=UP
GPIO 6: level=1 fsel=0 func=INPUT pull=UP
GPIO 7: level=1 fsel=0 func=INPUT pull=UP
GPIO 8: level=1 fsel=0 func=INPUT pull=UP
GPIO 9: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 10: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 11: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 12: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 13: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 14: level=1 fsel=0 func=INPUT pull=NONE
GPIO 15: level=1 fsel=0 func=INPUT pull=UP
GPIO 16: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 17: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 18: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 19: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 20: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 21: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 22: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 23: level=0 fsel=1 func=OUTPUT pull=NONE
GPIO 24: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 25: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 26: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 27: level=0 fsel=0 func=INPUT pull=DOWN
BANK1 (GPIO 28 to 45):
GPIO 28: level=1 fsel=2 alt=5 func=RGMII_MDIO pull=UP
GPIO 29: level=0 fsel=2 alt=5 func=RGMII_MDC pull=DOWN
GPIO 30: level=0 fsel=7 alt=3 func=CTS0 pull=UP
GPIO 31: level=0 fsel=7 alt=3 func=RTS0 pull=NONE
GPIO 32: level=1 fsel=7 alt=3 func=TXD0 pull=NONE
GPIO 33: level=1 fsel=7 alt=3 func=RXD0 pull=UP
GPIO 34: level=1 fsel=7 alt=3 func=SD1_CLK pull=NONE
GPIO 35: level=1 fsel=7 alt=3 func=SD1_CMD pull=UP
GPIO 36: level=1 fsel=7 alt=3 func=SD1_DAT0 pull=UP
GPIO 37: level=1 fsel=7 alt=3 func=SD1_DAT1 pull=UP
GPIO 38: level=1 fsel=7 alt=3 func=SD1_DAT2 pull=UP
GPIO 39: level=1 fsel=7 alt=3 func=SD1_DAT3 pull=UP
GPIO 40: level=0 fsel=4 alt=0 func=PWM1_0 pull=NONE
GPIO 41: level=0 fsel=4 alt=0 func=PWM1_1 pull=NONE
GPIO 42: level=0 fsel=1 func=OUTPUT pull=UP
GPIO 43: level=1 fsel=0 func=INPUT pull=UP
GPIO 44: level=1 fsel=0 func=INPUT pull=UP
GPIO 45: level=1 fsel=0 func=INPUT pull=UP
BANK2 (GPIO 46 to 53):
GPIO 46: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 47: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 48: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 49: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 50: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 51: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 52: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 53: level=0 fsel=0 func=INPUT pull=DOWN

vcdbg log messages
------------------

002670.230: arasan: arasan_emmc_open
002672.420: arasan: arasan_emmc_set_clock C0: 0x00000000 C1: 0x000ef447 emmc: 200000000 actual: 200000 div: 0x000001f4 target: 200000 min: 100000 max: 400000 delay: 10
002789.189: arasan: arasan_emmc_set_clock C0: 0x00000000 C1: 0x000ef447 emmc: 200000000 actual: 200000 div: 0x000001f4 target: 200000 min: 100000 max: 400000 delay: 10
002796.343: arasan: arasan_emmc_set_clock C0: 0x00000f00 C1: 0x000e01c7 emmc: 200000000 actual: 130039 div: 0x00000301 target: 130000 min: 100000 max: 400000 delay: 15
002838.933: arasan: arasan_emmc_set_clock C0: 0x00000f06 C1: 0x000e0307 emmc: 200000000 actual: 33333333 div: 0x00000003 target: 40000000 min: 0 max: 40000000 delay: 1
003139.347: brfs: File read: /mfs/sd/config.txt
003140.085: brfs: File read: 1747 bytes
003185.745: bootloader_eeprom_find_files unexpected length: 0xffffffffn
003196.209: brfs: File read: /mfs/sd/config.txt
003397.128: gpioman: gpioman_get_pin_num: pin DISPLAY_DSI_PORT not defined
003399.601: *** Restart logging
003399.639: brfs: File read: 1747 bytes
003436.372: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
003436.407: HDMI0: hdmi_pixel_encoding: 300000000

003436.421: HDMI1: hdmi_pixel_encoding: 300000000

003437.706: brfs: File read: /mfs/sd/cmdline.txt
003437.789: Read command line from file 'cmdline.txt':
003437.831: 'fsck.mode=force usb-storage.quirks=152d:0578:u,1058:1140:u dwc_otg.lpm_enable=0 console=serial0,115200 console=tty1 root=PARTUUID=698e33bd-01 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait ipv6.disable=1'
003438.123: brfs: File read: 487 bytes
004247.053: brfs: File read: /mfs/sd/kernel7l.img
004247.118: Loading 'kernel7l.img' to 0x8000 size 0x55d880
004251.536: No kernel trailer - assuming DT-capable
004251.630: brfs: File read: 5625984 bytes
004263.090: brfs: File read: /mfs/sd/bcm2711-rpi-4-b.dtb
004263.153: Loading 'bcm2711-rpi-4-b.dtb' to 0x565880 size 0x9e6f
004572.988: brfs: File read: 40559 bytes
004576.672: brfs: File read: /mfs/sd/config.txt
004577.407: dtparam: audio=on
004614.287: brfs: File read: 1747 bytes
004661.234: brfs: File read: /mfs/sd/overlays/vc4-fkms-v3d.dtbo
004718.727: Loaded overlay 'vc4-fkms-v3d'
006203.480: Device tree loaded to 0x1a7e5c00 (size 0xa3e4)
006206.128: gpioman: gpioman_get_pin_num: pin SDCARD_CONTROL_POWER not defined
008902.583: vchiq_core: vchiq_init_state: slot_zero = 0xca580000, is_master = 1
008906.030: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
008912.346: TV service:host side not connected, dropping notification 0x00000002, 0x00000001, 0x00000010
020783.801: brfs: File read: 1255 bytes
021485.401: TV service:host side not connected, dropping notification 0x00000008, 0x00000004, 0x00000000
1866353.078: TV service:host side not connected, dropping notification 0x00000001, 0x00000002, 0x00000000
1866407.776: TV service:host side not connected, dropping notification 0x00000002, 0x00000004, 0x00000000

dmesg log
---------

Forum troubleshooting thread - link

@rowanalex123 rowanalex123 changed the title OOM issue on Pi 4 with Buster USB3 disk writes trigger OOM reaper on Pi 4 Sep 6, 2019
@pelwell
Copy link
Contributor

pelwell commented Sep 6, 2019

  1. What does lsusb report?
  2. How are you powering the SSD?
  3. There is a new test firmware for the VL805 that seems to be very promising. You can download it here: https://drive.google.com/file/d/1nUFfKGI118bJ6DmiDm9euE6kWbOxbG7q/view?usp=sharing

@rowanalex123
Copy link
Author

rowanalex123 commented Sep 6, 2019

The SSD is powered using the official 3A Pi 4 power supply. vl805_update_0137ab does not fix the issue. The WD USB disk drive is powered by it's own power supply. I'm testing on the SSD only.

Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 003: ID 152d:0578 JMicron Technology Corp. / JMicron USA Technology Corp. JMS567 SATA 6Gb/s bridge
Bus 002 Device 002: ID 1058:1140 Western Digital Technologies, Inc. My Book Essential (WDBACW)
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 002: ID 2109:3431 VIA Labs, Inc. Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

After the firmware upgrade, I ran:

sudo ./vl805
VL805 FW version: 000137ab

sudo dd if=/dev/zero of=/home/pi/test.tmp bs=4M count=3824

dmesg output

sudo dmesg
[  669.808484] device-mapper: ioctl: 4.39.0-ioctl (2018-04-03) initialised: [email protected]
[  669.996916] NET: Registered protocol family 38
[  670.013086] cryptd: max_cpu_qlen set to 1000
[  674.981739] EXT4-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null)
[ 2690.825013] lxpanel invoked oom-killer: gfp_mask=0x7080c0(GFP_KERNEL_ACCOUNT|__GFP_ZERO), nodemask=(null), order=1, oom_score_adj=0
[ 2690.825022] lxpanel cpuset=/ mems_allowed=0
[ 2690.825040] CPU: 0 PID: 870 Comm: lxpanel Tainted: G         C        4.19.66-v7l+ #1253
[ 2690.825043] Hardware name: BCM2835
[ 2690.825071] [<c0212c7c>] (unwind_backtrace) from [<c020d49c>] (show_stack+0x20/0x24)
[ 2690.825082] [<c020d49c>] (show_stack) from [<c097f080>] (dump_stack+0xd4/0x118)
[ 2690.825095] [<c097f080>] (dump_stack) from [<c033f5b4>] (dump_header+0x80/0x250)
[ 2690.825104] [<c033f5b4>] (dump_header) from [<c033e92c>] (oom_kill_process+0x358/0x3a8)
[ 2690.825113] [<c033e92c>] (oom_kill_process) from [<c033f25c>] (out_of_memory+0x134/0x36c)
[ 2690.825122] [<c033f25c>] (out_of_memory) from [<c0345620>] (__alloc_pages_nodemask+0xfc0/0x1180)
[ 2690.825133] [<c0345620>] (__alloc_pages_nodemask) from [<c021f5d0>] (copy_process.part.5+0x1f4/0x1ad4)
[ 2690.825141] [<c021f5d0>] (copy_process.part.5) from [<c0221078>] (_do_fork+0xd8/0x438)
[ 2690.825146] [<c0221078>] (_do_fork) from [<c02214fc>] (sys_clone+0x34/0x3c)
[ 2690.825153] [<c02214fc>] (sys_clone) from [<c0201000>] (ret_fast_syscall+0x0/0x28)
[ 2690.825157] Exception stack(0xc64d3fa8 to 0xc64d3ff0)
[ 2690.825162] 3fa0:                   b57311d8 00000001 01200011 00000000 00000000 00000000
[ 2690.825168] 3fc0: b57311d8 00000001 b3d15a40 00000078 00000001 b6473000 b5731630 00000013
[ 2690.825171] 3fe0: b5731170 beec16c0 b63c8854 b63c8788
[ 2690.825175] Mem-Info:
[ 2690.825185] active_anon:24288 inactive_anon:31049 isolated_anon:1
                active_file:8763 inactive_file:360689 isolated_file:0
                unevictable:16 dirty:6541 writeback:628 unstable:0
                slab_reclaimable:13552 slab_unreclaimable:11228
                mapped:12179 shmem:19585 pagetables:1503 bounce:0
                free:393281 free_pcp:64 free_cma:46791
[ 2690.825194] Node 0 active_anon:97152kB inactive_anon:124196kB active_file:35052kB inactive_file:1442756kB unevictable:64kB isolated(anon):4kB isolated(file):0kB mapped:48716kB dirty:26164kB writeback:2512kB shmem:78340kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
[ 2690.825203] DMA free:203832kB min:16384kB low:20480kB high:24576kB active_anon:0kB inactive_anon:0kB active_file:3252kB inactive_file:344kB unevictable:0kB writepending:0kB present:434176kB managed:388116kB mlocked:0kB kernel_stack:3424kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:187164kB
[ 2690.825207] lowmem_reserve[]: 0 0 3008 3008
[ 2690.825232] HighMem free:1369292kB min:512kB low:33016kB high:65520kB active_anon:97300kB inactive_anon:124196kB active_file:31800kB inactive_file:1442292kB unevictable:64kB writepending:28704kB present:3080192kB managed:3080192kB mlocked:64kB kernel_stack:0kB pagetables:6012kB bounce:0kB free_pcp:384kB local_pcp:0kB free_cma:0kB
[ 2690.825235] lowmem_reserve[]: 0 0 0 0
[ 2690.825254] DMA: 317*4kB (UEC) 258*8kB (UE) 220*16kB (UEC) 102*32kB (UEH) 64*64kB (UE) 22*128kB (UEHC) 2*256kB (C) 2*512kB (C) 3*1024kB (C) 3*2048kB (C) 43*4096kB (C) = 203908kB
[ 2690.825336] HighMem: 4872*4kB (UM) 995*8kB (UM) 68*16kB (UM) 38*32kB (UM) 28*64kB (UM) 245*128kB (UM) 1453*256kB (UM) 580*512kB (UM) 149*1024kB (UM) 79*2048kB (UM) 79*4096kB (M) = 1369784kB
[ 2690.825417] 393633 total pagecache pages
[ 2690.825426] 4700 pages in swap cache
[ 2690.825430] Swap cache stats: add 84212, delete 79512, find 21231/29672
[ 2690.825434] Free swap  = 3944188kB
[ 2690.825437] Total swap = 4194300kB
[ 2690.825441] 878592 pages RAM
[ 2690.825445] 770048 pages HighMem/MovableOnly
[ 2690.825448] 11515 pages reserved
[ 2690.825451] 65536 pages cma reserved
[ 2690.825455] Tasks state (memory values in pages):
[ 2690.825459] [  pid  ]   uid  tgid total_vm      rss pgtables_bytes swapents oom_score_adj name
[ 2690.825475] [    127]     0   127     5347      864   204800      202             0 systemd-journal
[ 2690.825481] [    239]     0   239     4606      457    45056      199         -1000 systemd-udevd
[ 2690.825490] [    386]   100   386     5592      547    57344      147             0 systemd-timesyn
[ 2690.825496] [    425]     0   425     1986      425    36864       39             0 cron
[ 2690.825503] [    426]   108   426     1443      464    36864       51             0 avahi-daemon
[ 2690.825510] [    428] 65534   428     1080      323    36864       37             0 thd
[ 2690.825516] [    430]     0   430     2392      279    40960       83             0 cron
[ 2690.825522] [    431]     0   431    19555      736   110592      656             0 udisksd
[ 2690.825528] [    433]     0   433      923      295    32768       46             0 alsactl
[ 2690.825534] [    436]     0   436     3275      553    49152      129             0 systemd-logind
[ 2690.825539] [    448]     0   448     6378      428    53248      183             0 rsyslogd
[ 2690.825545] [    452]   104   452     1704      438    40960      168          -900 dbus-daemon
[ 2690.825550] [    458]     0   458     2675      443    45056       88             0 wpa_supplicant
[ 2690.825556] [    462]     0   462     6914        0    40960       25             0 rngd
[ 2690.825562] [    466]   108   466     1443        0    32768       63             0 avahi-daemon
[ 2690.825568] [    471]  1000   471      485       53    24576       18             0 sh
[ 2690.825574] [    475]  1000   475     3915      293    53248     1308             0 python
[ 2690.825580] [    483]     0   483      740      299    28672      102             0 dhcpcd
[ 2690.825585] [    536]     0   536     7994      530    90112      317             0 nmbd
[ 2690.825591] [    543]     0   543     2094      211    40960       55             0 vncserver-x11-s
[ 2690.825597] [    544]     0   544    11067     1069    94208     1368             0 unattended-upgr
[ 2690.825603] [    546]     0   546    12812     2388    90112      249             0 fail2ban-server
[ 2690.825608] [    552]     0   552    11425      630    86016      350             0 polkitd
[ 2690.825613] [    554]     0   554     8436      587    94208     2305             0 vncserver-x11-c
[ 2690.825619] [    557]     0   557   237176     1711   180224     2853             0 containerd
[ 2690.825624] [    560]     0   560   243656     2320   245760     5556          -500 dockerd
[ 2690.825629] [    572]     0   572    10026      821    73728        0             0 lightdm
[ 2690.825635] [    579]     0   579     2671      563    40960      116         -1000 sshd
[ 2690.825640] [    594]     0   594     2740      200    45056      125             0 wpa_supplicant
[ 2690.825646] [    610]     0   610    27543    10211   233472        0             0 Xorg
[ 2690.825651] [    611]     0   611     1431      385    36864      111             0 login
[ 2690.825657] [    634]     0   634     2869      488    49152      122             0 vncagent
[ 2690.825662] [    739]     0   739     8160      859    69632       11             0 lightdm
[ 2690.825668] [    750]  1000   750     3668      508    57344      263             0 systemd
[ 2690.825674] [    754]  1000   754     4231      235    53248      424             0 (sd-pam)
[ 2690.825680] [    773]  1000   773    14083     1002   102400      318             0 lxsession
[ 2690.825686] [    782]  1000   782     1636      398    32768      110             0 dbus-daemon
[ 2690.825693] [    821]  1000   821     1120      155    32768       69             0 ssh-agent
[ 2690.825699] [    838]  1000   838    10852      476    69632      169             0 gvfsd
[ 2690.825705] [    848]  1000   848    14192      548    81920      193             0 gvfsd-fuse
[ 2690.825710] [    864]  1000   864    16285     1113    98304      587             0 openbox
[ 2690.825716] [    868]  1000   868    11783      657    94208      206             0 lxpolkit
[ 2690.825722] [    870]  1000   870    37434     2161   192512      967             0 lxpanel
[ 2690.825728] [    871]  1000   871    20542     1608   122880      521             0 pcmanfm
[ 2690.825733] [    886]  1000   886     1120        0    32768       78             0 ssh-agent
[ 2690.825739] [    900]  1000   900      485       53    32768       17             0 cmstart.sh
[ 2690.825746] [    905]  1000   905      485       53    28672       26             0 kodi
[ 2690.825752] [    908]  1000   908     1218      111    36864       68             0 xcompmgr
[ 2690.825758] [    909]  1000   909   157839    13554   733184     1421             0 kodi.bin
[ 2690.825763] [    926]     0   926   199847      125    45056      114          -999 containerd-shim
[ 2690.825768] [    944]  9001   944      352       29    28672        8             0 tini
[ 2690.825774] [    952]  1000   952     7175      525    61440      141             0 menu-cached
[ 2690.825780] [    954]  1000   954    24506      846    98304      217             0 gvfs-udisks2-vo
[ 2690.825786] [    964]  1000   964    14005      475    81920      203             0 gvfs-afc-volume
[ 2690.825791] [    985]  1000   985    10025      253    69632      126             0 gvfs-goa-volume
[ 2690.825797] [   1001]  1000  1001    10031      279    73728      136             0 gvfs-mtp-volume
[ 2690.825804] [   1013]  1000  1013     7952      784    86016      529             0 vncserverui
[ 2690.825810] [   1020]  1000  1020    10423      291    65536      164             0 gvfs-gphoto2-vo
[ 2690.825817] [   1034]  1000  1034    13804      570    86016      244             0 gvfsd-trash
[ 2690.825822] [   1039]  1000  1039     7865      815    86016      378             0 vncserverui
[ 2690.825828] [   1078]  1000  1078    10895      298    77824      174             0 gnome-keyring-d
[ 2690.825834] [   1105]  1000  1105     2601      372    45056      273             0 zsh
[ 2690.825839] [   1109]  1000  1109     7744      221    65536      114             0 gvfsd-metadata
[ 2690.825845] [   1116]     0  1116    12087      617   122880      424             0 smbd
[ 2690.825850] [   1130]     0  1130    11356      400   102400      414             0 smbd-notifyd
[ 2690.825856] [   1131]     0  1131    11354      355   102400      414             0 cleanupd
[ 2690.825862] [   1136]     0  1136    12087      374   106496      427             0 lpqd
[ 2690.825868] [   1151]     0  1151      535        1    28672       31             0 hciattach
[ 2690.825874] [   1159]     0  1159     2452      316    40960       92             0 bluetoothd
[ 2690.825879] [   1168]     0  1168     6676      299    57344      112             0 bluealsa
[ 2690.825886] [   1210]  9001  1210   130992    14854   569344    30120             0 java
[ 2690.825892] [   2753]     0  2753     2701      679    49152        5             0 sshd
[ 2690.825898] [   2759]  1000  2759     2701      486    45056        4             0 sshd
[ 2690.825903] [   2761]  1000  2761     2632      625    49152        0             0 zsh
[ 2690.825909] [   2795]     0  2795     2701      703    49152        0             0 sshd
[ 2690.825915] [   2798]  1000  2798     2701      461    45056        0             0 sshd
[ 2690.825920] [   2800]  1000  2800     3354      762    49152        0             0 zsh
[ 2690.825926] [   2918]  1000  2918     1882      574    45056        0             0 watch
[ 2690.825935] [  17741]     0 17741     2514      712    40960        0             0 sudo
[ 2690.825941] [  17746]     0 17746     2650     1312    45056        0             0 dd
[ 2690.825948] Out of memory: Kill process 1210 (java) score 23 or sacrifice child
[ 2690.826172] Killed process 1210 (java) total-vm:523968kB, anon-rss:56164kB, file-rss:3252kB, shmem-rss:0kB
[ 2690.867610] oom_reaper: reaped process 1210 (java), now anon-rss:0kB, file-rss:16kB, shmem-rss:0kB
[ 2896.534660] lxpanel invoked oom-killer: gfp_mask=0x7080c0(GFP_KERNEL_ACCOUNT|__GFP_ZERO), nodemask=(null), order=1, oom_score_adj=0
[ 2896.534668] lxpanel cpuset=/ mems_allowed=0
[ 2896.534684] CPU: 3 PID: 870 Comm: lxpanel Tainted: G         C        4.19.66-v7l+ #1253
[ 2896.534687] Hardware name: BCM2835
[ 2896.534708] [<c0212c7c>] (unwind_backtrace) from [<c020d49c>] (show_stack+0x20/0x24)
[ 2896.534717] [<c020d49c>] (show_stack) from [<c097f080>] (dump_stack+0xd4/0x118)
[ 2896.534727] [<c097f080>] (dump_stack) from [<c033f5b4>] (dump_header+0x80/0x250)
[ 2896.534736] [<c033f5b4>] (dump_header) from [<c033e92c>] (oom_kill_process+0x358/0x3a8)
[ 2896.534744] [<c033e92c>] (oom_kill_process) from [<c033f25c>] (out_of_memory+0x134/0x36c)
[ 2896.534752] [<c033f25c>] (out_of_memory) from [<c0345620>] (__alloc_pages_nodemask+0xfc0/0x1180)
[ 2896.534762] [<c0345620>] (__alloc_pages_nodemask) from [<c021f5d0>] (copy_process.part.5+0x1f4/0x1ad4)
[ 2896.534769] [<c021f5d0>] (copy_process.part.5) from [<c0221078>] (_do_fork+0xd8/0x438)
[ 2896.534775] [<c0221078>] (_do_fork) from [<c02214fc>] (sys_clone+0x34/0x3c)
[ 2896.534782] [<c02214fc>] (sys_clone) from [<c0201000>] (ret_fast_syscall+0x0/0x28)
[ 2896.534786] Exception stack(0xc64d3fa8 to 0xc64d3ff0)
[ 2896.534790] 3fa0:                   b57311d8 00000001 01200011 00000000 00000000 00000000
[ 2896.534795] 3fc0: b57311d8 00000001 b3d15a40 00000078 00000001 b6473000 b5731630 00000013
[ 2896.534799] 3fe0: b5731170 beec16c0 b63c8854 b63c8788
[ 2896.534803] Mem-Info:
[ 2896.534814] active_anon:37559 inactive_anon:44097 isolated_anon:0
                active_file:8303 inactive_file:311069 isolated_file:0
                unevictable:16 dirty:4427 writeback:683 unstable:0
                slab_reclaimable:13049 slab_unreclaimable:11342
                mapped:12602 shmem:19501 pagetables:1545 bounce:0
                free:417099 free_pcp:140 free_cma:47312
[ 2896.534823] Node 0 active_anon:150236kB inactive_anon:176388kB active_file:33212kB inactive_file:1244276kB unevictable:64kB isolated(anon):0kB isolated(file):0kB mapped:50408kB dirty:17708kB writeback:2732kB shmem:78004kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
[ 2896.534832] DMA free:207016kB min:16384kB low:20480kB high:24576kB active_anon:0kB inactive_anon:0kB active_file:1112kB inactive_file:336kB unevictable:0kB writepending:0kB present:434176kB managed:388116kB mlocked:0kB kernel_stack:3752kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:189248kB
[ 2896.534835] lowmem_reserve[]: 0 0 3008 3008
[ 2896.534860] HighMem free:1461380kB min:512kB low:33016kB high:65520kB active_anon:150236kB inactive_anon:176536kB active_file:32100kB inactive_file:1243552kB unevictable:64kB writepending:20616kB present:3080192kB managed:3080192kB mlocked:64kB kernel_stack:0kB pagetables:6180kB bounce:0kB free_pcp:676kB local_pcp:0kB free_cma:0kB
[ 2896.534863] lowmem_reserve[]: 0 0 0 0
[ 2896.534882] DMA: 522*4kB (UEHC) 568*8kB (UEHC) 337*16kB (UEHC) 117*32kB (UEHC) 48*64kB (UEHC) 6*128kB (C) 2*256kB (C) 4*512kB (C) 3*1024kB (C) 1*2048kB (C) 44*4096kB (C) = 207512kB
[ 2896.534964] HighMem: 153*4kB (UM) 98*8kB (U) 58*16kB (UM) 34*32kB (UM) 569*64kB (UM) 12*128kB (U) 266*256kB (UM) 788*512kB (UM) 317*1024kB (UM) 117*2048kB (UM) 94*4096kB (M) = 1462164kB
[ 2896.535044] 339613 total pagecache pages
[ 2896.535051] 845 pages in swap cache
[ 2896.535055] Swap cache stats: add 99831, delete 98988, find 29008/42747
[ 2896.535059] Free swap  = 4054268kB
[ 2896.535062] Total swap = 4194300kB
[ 2896.535066] 878592 pages RAM
[ 2896.535069] 770048 pages HighMem/MovableOnly
[ 2896.535073] 11515 pages reserved
[ 2896.535076] 65536 pages cma reserved
[ 2896.535080] Tasks state (memory values in pages):
[ 2896.535083] [  pid  ]   uid  tgid total_vm      rss pgtables_bytes swapents oom_score_adj name
[ 2896.535099] [    127]     0   127     5348      685   208896      205             0 systemd-journal
[ 2896.535105] [    239]     0   239     4606      256    45056      213         -1000 systemd-udevd
[ 2896.535112] [    386]   100   386     5592      267    57344      156             0 systemd-timesyn
[ 2896.535118] [    425]     0   425     1986      300    36864       31             0 cron
[ 2896.535123] [    426]   108   426     1443      347    36864       51             0 avahi-daemon
[ 2896.535129] [    428] 65534   428     1080      228    36864       39             0 thd
[ 2896.535134] [    430]     0   430     2392      107    40960       82             0 cron
[ 2896.535140] [    431]     0   431    19555      506   110592      664             0 udisksd
[ 2896.535145] [    433]     0   433      923      240    32768       47             0 alsactl
[ 2896.535150] [    436]     0   436     3275      298    49152      163             0 systemd-logind
[ 2896.535156] [    448]     0   448     6378      327    53248      191             0 rsyslogd
[ 2896.535161] [    452]   104   452     1704      275    40960      186          -900 dbus-daemon
[ 2896.535166] [    458]     0   458     2675      262    45056       88             0 wpa_supplicant
[ 2896.535171] [    462]     0   462     6914        0    40960       31             0 rngd
[ 2896.535177] [    466]   108   466     1443        1    32768       62             0 avahi-daemon
[ 2896.535182] [    471]  1000   471      485        0    24576       17             0 sh
[ 2896.535187] [    475]  1000   475     3915      664    53248     1088             0 python
[ 2896.535192] [    483]     0   483      740      201    28672      102             0 dhcpcd
[ 2896.535197] [    536]     0   536     7994      385    90112      320             0 nmbd
[ 2896.535203] [    543]     0   543     2094      116    40960       54             0 vncserver-x11-s
[ 2896.535208] [    544]     0   544    11067      783    94208     1375             0 unattended-upgr
[ 2896.535213] [    546]     0   546    12812     1530    90112     1106             0 fail2ban-server
[ 2896.535219] [    552]     0   552    11425      481    86016      353             0 polkitd
[ 2896.535224] [    554]     0   554     8436      444    94208     2328             0 vncserver-x11-c
[ 2896.535229] [    557]     0   557   237176     1237   180224     3289             0 containerd
[ 2896.535234] [    560]     0   560   245705       80   249856     7683          -500 dockerd
[ 2896.535240] [    572]     0   572    10026      675    73728        0             0 lightdm
[ 2896.535245] [    579]     0   579     2671      259    40960      116         -1000 sshd
[ 2896.535250] [    594]     0   594     2740      219    45056      126             0 wpa_supplicant
[ 2896.535256] [    610]     0   610    27543    10081   233472        0             0 Xorg
[ 2896.535261] [    611]     0   611     1431      191    36864      114             0 login
[ 2896.535266] [    634]     0   634     2869      390    49152      121             0 vncagent
[ 2896.535271] [    739]     0   739     8160      639    69632       10             0 lightdm
[ 2896.535277] [    750]  1000   750     3668      236    57344      271             0 systemd
[ 2896.535282] [    754]  1000   754     4231      135    53248      430             0 (sd-pam)
[ 2896.535287] [    773]  1000   773    14083      878   102400      318             0 lxsession
[ 2896.535292] [    782]  1000   782     1636      265    32768      112             0 dbus-daemon
[ 2896.535297] [    821]  1000   821     1120      141    32768       69             0 ssh-agent
[ 2896.535303] [    838]  1000   838    10852      349    69632      168             0 gvfsd
[ 2896.535308] [    848]  1000   848    14192      452    81920      192             0 gvfsd-fuse
[ 2896.535313] [    864]  1000   864    16285      960    98304      587             0 openbox
[ 2896.535318] [    868]  1000   868    11783      536    94208      206             0 lxpolkit
[ 2896.535324] [    870]  1000   870    37467     2068   192512      949             0 lxpanel
[ 2896.535329] [    871]  1000   871    20542     1418   122880      552             0 pcmanfm
[ 2896.535351] [    886]  1000   886     1120        1    32768       77             0 ssh-agent
[ 2896.535356] [    900]  1000   900      485        0    32768       16             0 cmstart.sh
[ 2896.535361] [    905]  1000   905      485        0    28672       25             0 kodi
[ 2896.535367] [    908]  1000   908     1218       35    36864       67             0 xcompmgr
[ 2896.535372] [    909]  1000   909   157839    12995   733184     1421             0 kodi.bin
[ 2896.535377] [    952]  1000   952     7175      431    61440      141             0 menu-cached
[ 2896.535382] [    954]  1000   954    24506      586    98304      413             0 gvfs-udisks2-vo
[ 2896.535387] [    964]  1000   964    14005      344    81920      202             0 gvfs-afc-volume
[ 2896.535392] [    985]  1000   985    10025      124    69632      125             0 gvfs-goa-volume
[ 2896.535397] [   1001]  1000  1001    10031      154    73728      135             0 gvfs-mtp-volume
[ 2896.535403] [   1013]  1000  1013     7952      616    86016      559             0 vncserverui
[ 2896.535408] [   1020]  1000  1020    10423      157    65536      163             0 gvfs-gphoto2-vo
[ 2896.535414] [   1034]  1000  1034    13804      498    86016      244             0 gvfsd-trash
[ 2896.535419] [   1039]  1000  1039     7865      672    86016      377             0 vncserverui
[ 2896.535424] [   1078]  1000  1078    10895      159    77824      173             0 gnome-keyring-d
[ 2896.535429] [   1105]  1000  1105     2601      262    45056      282             0 zsh
[ 2896.535434] [   1109]  1000  1109     7744       99    65536      113             0 gvfsd-metadata
[ 2896.535439] [   1116]     0  1116    12087      310   122880      491             0 smbd
[ 2896.535445] [   1130]     0  1130    11356      248   102400      472             0 smbd-notifyd
[ 2896.535450] [   1131]     0  1131    11354      216   102400      471             0 cleanupd
[ 2896.535455] [   1136]     0  1136    12087      224   106496      485             0 lpqd
[ 2896.535462] [   1151]     0  1151      535        2    28672       30             0 hciattach
[ 2896.535467] [   1159]     0  1159     2452      208    40960       99             0 bluetoothd
[ 2896.535472] [   1168]     0  1168     6676      188    57344      116             0 bluealsa
[ 2896.535477] [   2753]     0  2753     2701      270    49152      133             0 sshd
[ 2896.535482] [   2759]  1000  2759     2701      347    45056      117             0 sshd
[ 2896.535487] [   2761]  1000  2761     2632      827    49152        0             0 zsh
[ 2896.535492] [   2795]     0  2795     2701      409    49152        0             0 sshd
[ 2896.535497] [   2798]  1000  2798     2701      465    45056        0             0 sshd
[ 2896.535502] [   2800]  1000  2800     3354      617    49152        0             0 zsh
[ 2896.535512] [  17741]     0 17741     2514      362    40960        0             0 sudo
[ 2896.535517] [  17746]     0 17746     2650     1216    45056        0             0 dd
[ 2896.535523] [  18353]     0 18353   199671      166    45056       92          -999 containerd-shim
[ 2896.535528] [  18373]  9001 18373      352       45    28672        8             0 tini
[ 2896.535533] [  18554]  9001 18554   130520    43107   569344     1766             0 java
[ 2896.535540] [  19220]     0 19220     2701      821    45056        0             0 sshd
[ 2896.535544] [  19228]  1000 19228     2701      663    45056        0             0 sshd
[ 2896.535549] [  19230]  1000 19230     2632      827    45056        0             0 zsh
[ 2896.535555] [  19282]     0 19282     2514      724    40960        0             0 sudo
[ 2896.535560] [  19330]     0 19330     4649     2330    65536        0             0 iotop
[ 2896.535565] Out of memory: Kill process 18554 (java) score 23 or sacrifice child
[ 2896.535844] Killed process 18554 (java) total-vm:522080kB, anon-rss:169252kB, file-rss:3176kB, shmem-rss:0kB
[ 2896.572585] oom_reaper: reaped process 18554 (java), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
[ 2896.572963] lxpanel invoked oom-killer: gfp_mask=0x7080c0(GFP_KERNEL_ACCOUNT|__GFP_ZERO), nodemask=(null), order=1, oom_score_adj=0
[ 2896.572968] lxpanel cpuset=/ mems_allowed=0
[ 2896.572985] CPU: 3 PID: 870 Comm: lxpanel Tainted: G         C        4.19.66-v7l+ #1253
[ 2896.572988] Hardware name: BCM2835
[ 2896.573008] [<c0212c7c>] (unwind_backtrace) from [<c020d49c>] (show_stack+0x20/0x24)
[ 2896.573018] [<c020d49c>] (show_stack) from [<c097f080>] (dump_stack+0xd4/0x118)
[ 2896.573029] [<c097f080>] (dump_stack) from [<c033f5b4>] (dump_header+0x80/0x250)
[ 2896.573038] [<c033f5b4>] (dump_header) from [<c033e92c>] (oom_kill_process+0x358/0x3a8)
[ 2896.573046] [<c033e92c>] (oom_kill_process) from [<c033f25c>] (out_of_memory+0x134/0x36c)
[ 2896.573054] [<c033f25c>] (out_of_memory) from [<c0345620>] (__alloc_pages_nodemask+0xfc0/0x1180)
[ 2896.573063] [<c0345620>] (__alloc_pages_nodemask) from [<c021f5d0>] (copy_process.part.5+0x1f4/0x1ad4)
[ 2896.573069] [<c021f5d0>] (copy_process.part.5) from [<c0221078>] (_do_fork+0xd8/0x438)
[ 2896.573075] [<c0221078>] (_do_fork) from [<c02214fc>] (sys_clone+0x34/0x3c)
[ 2896.573082] [<c02214fc>] (sys_clone) from [<c0201000>] (ret_fast_syscall+0x0/0x28)
[ 2896.573086] Exception stack(0xc64d3fa8 to 0xc64d3ff0)
[ 2896.573091] 3fa0:                   b57311d8 00000001 01200011 00000000 00000000 00000000
[ 2896.573096] 3fc0: b57311d8 00000001 b3d15a40 00000078 00000001 b6473000 b5731630 00000013
[ 2896.573100] 3fe0: b5731170 beec16c0 b63c8854 b63c8788
[ 2896.573104] Mem-Info:
[ 2896.573114] active_anon:16234 inactive_anon:22806 isolated_anon:0
                active_file:8340 inactive_file:299336 isolated_file:0
                unevictable:16 dirty:5833 writeback:276 unstable:0
                slab_reclaimable:12901 slab_unreclaimable:11342
                mapped:11529 shmem:19501 pagetables:1545 bounce:0
                free:471456 free_pcp:316 free_cma:47312
[ 2896.573122] Node 0 active_anon:64936kB inactive_anon:91224kB active_file:33360kB inactive_file:1197344kB unevictable:64kB isolated(anon):0kB isolated(file):0kB mapped:46116kB dirty:23332kB writeback:1104kB shmem:78004kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
[ 2896.573132] DMA free:207520kB min:16384kB low:20480kB high:24576kB active_anon:0kB inactive_anon:0kB active_file:1112kB inactive_file:336kB unevictable:0kB writepending:0kB present:434176kB managed:388116kB mlocked:0kB kernel_stack:3752kB pagetables:0kB bounce:0kB free_pcp:4kB local_pcp:0kB free_cma:189248kB
[ 2896.573135] lowmem_reserve[]: 0 0 3008 3008
[ 2896.573160] HighMem free:1678304kB min:512kB low:33016kB high:65520kB active_anon:65060kB inactive_anon:92368kB active_file:32100kB inactive_file:1197576kB unevictable:64kB writepending:25128kB present:3080192kB managed:3080192kB mlocked:64kB kernel_stack:0kB pagetables:6180kB bounce:0kB free_pcp:1260kB local_pcp:0kB free_cma:0kB
[ 2896.573163] lowmem_reserve[]: 0 0 0 0
[ 2896.573182] DMA: 545*4kB (UEHC) 599*8kB (UEHC) 362*16kB (UEHC) 118*32kB (UEHC) 48*64kB (UEHC) 6*128kB (C) 2*256kB (C) 4*512kB (C) 3*1024kB (C) 1*2048kB (C) 44*4096kB (C) = 208284kB
[ 2896.573265] HighMem: 7376*4kB (UM) 4935*8kB (UM) 2448*16kB (UM) 1170*32kB (UM) 1500*64kB (UM) 112*128kB (UM) 274*256kB (UM) 788*512kB (UM) 317*1024kB (UM) 117*2048kB (UM) 94*4096kB (M) = 1678776kB
[ 2896.573346] 327831 total pagecache pages
[ 2896.573353] 720 pages in swap cache
[ 2896.573357] Swap cache stats: add 99859, delete 99141, find 29013/42779
[ 2896.573361] Free swap  = 4061692kB
[ 2896.573365] Total swap = 4194300kB
[ 2896.573368] 878592 pages RAM
[ 2896.573372] 770048 pages HighMem/MovableOnly
[ 2896.573375] 11515 pages reserved
[ 2896.573379] 65536 pages cma reserved
[ 2896.573383] Tasks state (memory values in pages):
[ 2896.573386] [  pid  ]   uid  tgid total_vm      rss pgtables_bytes swapents oom_score_adj name
[ 2896.573403] [    127]     0   127     5348      683   208896      205             0 systemd-journal
[ 2896.573409] [    239]     0   239     4606      256    45056      213         -1000 systemd-udevd
[ 2896.573417] [    386]   100   386     5592      267    57344      156             0 systemd-timesyn
[ 2896.573422] [    425]     0   425     1986      300    36864       31             0 cron
[ 2896.573428] [    426]   108   426     1443      347    36864       51             0 avahi-daemon
[ 2896.573433] [    428] 65534   428     1080      228    36864       39             0 thd
[ 2896.573439] [    430]     0   430     2392      107    40960       82             0 cron
[ 2896.573444] [    431]     0   431    19555      506   110592      664             0 udisksd
[ 2896.573450] [    433]     0   433      923      240    32768       47             0 alsactl
[ 2896.573455] [    436]     0   436     3275      298    49152      163             0 systemd-logind
[ 2896.573460] [    448]     0   448     6378      326    53248      191             0 rsyslogd
[ 2896.573466] [    452]   104   452     1704      275    40960      186          -900 dbus-daemon
[ 2896.573471] [    458]     0   458     2675      262    45056       88             0 wpa_supplicant
[ 2896.573477] [    462]     0   462     6914        0    40960       31             0 rngd
[ 2896.573483] [    466]   108   466     1443        1    32768       62             0 avahi-daemon
[ 2896.573489] [    471]  1000   471      485        0    24576       17             0 sh
[ 2896.573495] [    475]  1000   475     3915      664    53248     1088             0 python
[ 2896.573501] [    483]     0   483      740      201    28672      102             0 dhcpcd
[ 2896.573506] [    536]     0   536     7994      385    90112      320             0 nmbd
[ 2896.573512] [    543]     0   543     2094      116    40960       54             0 vncserver-x11-s
[ 2896.573518] [    544]     0   544    11067      783    94208     1375             0 unattended-upgr
[ 2896.573524] [    546]     0   546    12812     1530    90112     1106             0 fail2ban-server
[ 2896.573529] [    552]     0   552    11425      481    86016      353             0 polkitd
[ 2896.573535] [    554]     0   554     8436      444    94208     2328             0 vncserver-x11-c
[ 2896.573541] [    557]     0   557   237176     1237   180224     3289             0 containerd
[ 2896.573547] [    560]     0   560   245705       80   249856     7683          -500 dockerd
[ 2896.573552] [    572]     0   572    10026      675    73728        0             0 lightdm
[ 2896.573558] [    579]     0   579     2671      259    40960      116         -1000 sshd
[ 2896.573565] [    594]     0   594     2740      219    45056      126             0 wpa_supplicant
[ 2896.573571] [    610]     0   610    27543    10081   233472        0             0 Xorg
[ 2896.573577] [    611]     0   611     1431      191    36864      114             0 login
[ 2896.573582] [    634]     0   634     2869      390    49152      121             0 vncagent
[ 2896.573588] [    739]     0   739     8160      639    69632       10             0 lightdm
[ 2896.573594] [    750]  1000   750     3668      236    57344      271             0 systemd
[ 2896.573600] [    754]  1000   754     4231      135    53248      430             0 (sd-pam)
[ 2896.573606] [    773]  1000   773    14083      878   102400      318             0 lxsession
[ 2896.573611] [    782]  1000   782     1636      265    32768      112             0 dbus-daemon
[ 2896.573617] [    821]  1000   821     1120      141    32768       69             0 ssh-agent
[ 2896.573623] [    838]  1000   838    10852      349    69632      168             0 gvfsd
[ 2896.573629] [    848]  1000   848    14192      452    81920      192             0 gvfsd-fuse
[ 2896.573635] [    864]  1000   864    16285      960    98304      587             0 openbox
[ 2896.573641] [    868]  1000   868    11783      536    94208      206             0 lxpolkit
[ 2896.573647] [    870]  1000   870    37467     2068   192512      949             0 lxpanel
[ 2896.573654] [    871]  1000   871    20542     1418   122880      552             0 pcmanfm
[ 2896.573661] [    886]  1000   886     1120        1    32768       77             0 ssh-agent
[ 2896.573668] [    900]  1000   900      485        0    32768       16             0 cmstart.sh
[ 2896.573673] [    905]  1000   905      485        0    28672       25             0 kodi
[ 2896.573679] [    908]  1000   908     1218       35    36864       67             0 xcompmgr
[ 2896.573684] [    909]  1000   909   157839    12995   733184     1421             0 kodi.bin
[ 2896.573690] [    952]  1000   952     7175      431    61440      141             0 menu-cached
[ 2896.573696] [    954]  1000   954    24506      586    98304      413             0 gvfs-udisks2-vo
[ 2896.573702] [    964]  1000   964    14005      344    81920      202             0 gvfs-afc-volume
[ 2896.573708] [    985]  1000   985    10025      124    69632      125             0 gvfs-goa-volume
[ 2896.573714] [   1001]  1000  1001    10031      154    73728      135             0 gvfs-mtp-volume
[ 2896.573720] [   1013]  1000  1013     7952      616    86016      559             0 vncserverui
[ 2896.573726] [   1020]  1000  1020    10423      157    65536      163             0 gvfs-gphoto2-vo
[ 2896.573731] [   1034]  1000  1034    13804      498    86016      244             0 gvfsd-trash
[ 2896.573737] [   1039]  1000  1039     7865      672    86016      377             0 vncserverui
[ 2896.573743] [   1078]  1000  1078    10895      159    77824      173             0 gnome-keyring-d
[ 2896.573750] [   1105]  1000  1105     2601      262    45056      282             0 zsh
[ 2896.573755] [   1109]  1000  1109     7744       99    65536      113             0 gvfsd-metadata
[ 2896.573761] [   1116]     0  1116    12087      310   122880      491             0 smbd
[ 2896.573767] [   1130]     0  1130    11356      248   102400      472             0 smbd-notifyd
[ 2896.573774] [   1131]     0  1131    11354      216   102400      471             0 cleanupd
[ 2896.573781] [   1136]     0  1136    12087      224   106496      485             0 lpqd
[ 2896.573787] [   1151]     0  1151      535        2    28672       30             0 hciattach
[ 2896.573793] [   1159]     0  1159     2452      208    40960       99             0 bluetoothd
[ 2896.573798] [   1168]     0  1168     6676      188    57344      116             0 bluealsa
[ 2896.573804] [   2753]     0  2753     2701      270    49152      133             0 sshd
[ 2896.573809] [   2759]  1000  2759     2701      347    45056      117             0 sshd
[ 2896.573816] [   2761]  1000  2761     2632      827    49152        0             0 zsh
[ 2896.573822] [   2795]     0  2795     2701      409    49152        0             0 sshd
[ 2896.573828] [   2798]  1000  2798     2701      465    45056        0             0 sshd
[ 2896.573834] [   2800]  1000  2800     3354      617    49152        0             0 zsh
[ 2896.573846] [  17741]     0 17741     2514      362    40960        0             0 sudo
[ 2896.573851] [  17746]     0 17746     2650     1216    45056        0             0 dd
[ 2896.573858] [  18353]     0 18353   199671      166    45056       92          -999 containerd-shim
[ 2896.573864] [  18373]  9001 18373      352       45    28672        8             0 tini
[ 2896.573872] [  18644]  9001 18554   130520        0   569344        0             0 C1 CompilerThre
[ 2896.573878] [  19220]     0 19220     2701      821    45056        0             0 sshd
[ 2896.573884] [  19228]  1000 19228     2701      663    45056        0             0 sshd
[ 2896.573889] [  19230]  1000 19230     2632      827    45056        0             0 zsh
[ 2896.573894] [  19282]     0 19282     2514      724    40960        0             0 sudo
[ 2896.573901] [  19330]     0 19330     4649     2330    65536        0             0 iotop
[ 2896.573907] Out of memory: Kill process 909 (kodi.bin) score 7 or sacrifice child
[ 2896.574001] Killed process 909 (kodi.bin) total-vm:631356kB, anon-rss:30324kB, file-rss:21648kB, shmem-rss:8kB
[ 2896.589324] oom_reaper: reaped process 909 (kodi.bin), now anon-rss:16kB, file-rss:0kB, shmem-rss:8kB
[ 2986.581674] lxpanel invoked oom-killer: gfp_mask=0x7080c0(GFP_KERNEL_ACCOUNT|__GFP_ZERO), nodemask=(null), order=1, oom_score_adj=0
[ 2986.581681] lxpanel cpuset=/ mems_allowed=0
[ 2986.581698] CPU: 2 PID: 870 Comm: lxpanel Tainted: G         C        4.19.66-v7l+ #1253
[ 2986.581702] Hardware name: BCM2835
[ 2986.581723] [<c0212c7c>] (unwind_backtrace) from [<c020d49c>] (show_stack+0x20/0x24)
[ 2986.581733] [<c020d49c>] (show_stack) from [<c097f080>] (dump_stack+0xd4/0x118)
[ 2986.581746] [<c097f080>] (dump_stack) from [<c033f5b4>] (dump_header+0x80/0x250)
[ 2986.581755] [<c033f5b4>] (dump_header) from [<c033e92c>] (oom_kill_process+0x358/0x3a8)
[ 2986.581763] [<c033e92c>] (oom_kill_process) from [<c033f25c>] (out_of_memory+0x134/0x36c)
[ 2986.581771] [<c033f25c>] (out_of_memory) from [<c0345620>] (__alloc_pages_nodemask+0xfc0/0x1180)
[ 2986.581780] [<c0345620>] (__alloc_pages_nodemask) from [<c021f5d0>] (copy_process.part.5+0x1f4/0x1ad4)
[ 2986.581787] [<c021f5d0>] (copy_process.part.5) from [<c0221078>] (_do_fork+0xd8/0x438)
[ 2986.581793] [<c0221078>] (_do_fork) from [<c02214fc>] (sys_clone+0x34/0x3c)
[ 2986.581800] [<c02214fc>] (sys_clone) from [<c0201000>] (ret_fast_syscall+0x0/0x28)
.
.
.
**[ 2986.631754] Out of memory: Kill process 610 (Xorg) score 5 or sacrifice child
[ 2986.631783] Killed process 610 (Xorg) total-vm:110164kB, anon-rss:14388kB, file-rss:25568kB, shmem-rss:576kB**

@pelwell
Copy link
Contributor

pelwell commented Sep 6, 2019

Expecting the 4B to power an external SSD, even with a known-good power supply, is ambitious.

That particular USB<->SATA adaptor has been seen to cause problems.

@wushilin
Copy link

wushilin commented Dec 4, 2019

On the USB-SATA adapter part - I disagree. I use 2 Western Digital 8TB usb disks with ZFS, and it has same issue.

The WD disk has its own power supply. And I am using the genuine 5v3a standard power.

@randyoo
Copy link

randyoo commented Dec 10, 2019

@wushilin
I also had the same issue while running ZFS (and rsync), and it was gone after switching to the 64-bit kernel.

@mandev
Copy link

mandev commented Dec 13, 2019

Using the 64bit kernel did not solve the problem. At least for me.

@balajisraghavan
Copy link

Tried multiple SATA USB controllers including the Asmedia ASM1153. Issue still persists. Dont think its a power supply issue as well. I'm using the official power supply with no peripherals (keyboard, mouse etc) attached. Should be more than enough power to run the SATA SSD drive.

@JamesH65
Copy link
Contributor

Please update to the latest release kernel and retry, please report results.

@JamesH65 JamesH65 added the Waiting for external input Waiting for a comment from the originator of the issue, or a collaborator. label Feb 14, 2020
@balajisraghavan
Copy link

balajisraghavan commented Feb 14, 2020 via email

@bkev
Copy link

bkev commented Aug 20, 2020

I had this happen to my Pi last night too. I was doing a DD to a USB 3 hard drive and got the OOM errors in the syslog file.

This is what my Pi shows when I do a free -m (after a reboot). Is it strange that the swap is being slightly used even with so much memory spare?

          total        used        free      shared  buff/cache   available

Mem: 3776 450 266 159 3059 3068
Swap: 99 19 80

@Lipown
Copy link

Lipown commented Aug 24, 2020

Having same issue. Firstly caused by Transmission, then Deluge when downloading more torrents. Then just by coping files over network to PI. Tried to make huge swap without any solution. Now I am trying to disable oom killer by https://serverfault.com/questions/141988/avoid-linux-out-of-memory-application-teardown. It really driving me as I cannot use pi as a backup network storage. I have latest kernel and Raspberry OS.
EDIT: Nope I cannot disable OOM killer seems...

@bkev
Copy link

bkev commented Aug 25, 2020

I'm no expert, but it seems that it's just the data transfer that causes the issue, not the application then. I was just using dd to make a copy of the image to the USB 3 hard drive and I had the same issue, with OOM kicking in and killing all kinds of things in an attempt to get it to work.

I have a Pi v4 with 4Gb of RAM and I've never seen the amount used go over around 20% used.

I've not rebooted my pi since posting the memory above and it's now

total used free shared buff/cache available
Mem: 3776 483 165 235 3126 2970
Swap: 99 39 60

@rowanalex123
Copy link
Author

This issue is a definite deal breaker for anyone trying to use the Pi 4 as a desktop replacement or a media hub. Please look into this.

@bkev
Copy link

bkev commented Aug 25, 2020

@rowanalex123 So, are you still having the same issue, with the same things in the logs, even now?

I know that your level of detail in this post was what helped me figure out I was having the same, or a very similar issue.

I don't think it does it all the time for me, but last week whilst doing dd like you did, it slowed my Pi to a crawl and OOM starting closing all sorts of things down even though the memory seemed to be OK.

@rowanalex123
Copy link
Author

I've not tested it myself off late. Going by the above two reports though, think its safe to say the issue is not resolved with the latest kernel?

@bkev
Copy link

bkev commented Aug 25, 2020

I regularly run apt update and full-upgrade so I'm running the latest firmware, bootloader and kernel.

@Lipown
Copy link

Lipown commented Aug 25, 2020

I also tried huge 80GB swap but it's not used at all. I would like to have this resolved. When I had the storage drive as NTFS and transfer speeds were <20MBs that time over network I had not this issue but now since I have storage on ext4 I have speeds ~100MBs it's crashing by oom killer.

@pelwell
Copy link
Contributor

pelwell commented Aug 25, 2020

Can people seeing the problem please post the output of the following commands:

$ grep Revision /proc/cpuinfo
$ uname -a
$ vmstat

@pelwell
Copy link
Contributor

pelwell commented Aug 25, 2020

And:

$ lsusb

@bkev
Copy link

bkev commented Aug 25, 2020

I also tried huge 80GB swap but it's not used at all. I would like to have this resolved. When I had the storage drive as NTFS and transfer speeds were <20MBs that time over network I had not this issue but now since I have storage on ext4 I have speeds ~100MBs it's crashing by oom killer.

Actually this rings a bell with me. I have my external drive formatted as NTFS but I kept on getting all sorts of errors etc related to NTFS-3G, but I can't remember any issues with OOM. I reformatted the drive to ext4 and got the OOM error.

@bkev
Copy link

bkev commented Aug 25, 2020

Can people seeing the problem please post the output of the following commands:

$ grep Revision /proc/cpuinfo
$ uname -a
$ vmstat

Hi, thanks for the info. Here are the results of the commands on my Pi:
Revision : c03111

Linux raspberrypiv4 5.4.51-v7l+ #1333 SMP Mon Aug 10 16:51:40 BST 2020 armv7l GNU/Linux

procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
0 0 41472 224508 130100 3006784 0 0 5 19 5 22 2 2 95 1 0

Bus 002 Device 002: ID 1058:2627 Western Digital Technologies, Inc.
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 003: ID 1e3d:4083 Chipsbank Microelectronics Co., Ltd
Bus 001 Device 004: ID 0781:5583 SanDisk Corp. Ultra Fit
Bus 001 Device 002: ID 2109:3431 VIA Labs, Inc. Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

@pelwell
Copy link
Contributor

pelwell commented Aug 25, 2020

That's a rev 1.1 4B with 4GB RAM running a recent kernel. The rev 1.1 boards where fitted with BCM2711B0 - the first production silicon - which had a few restrictions that were improved in the later C0 revision:

  1. The EMMC2 bus can only directly address the first 1GB.
  2. The PCIe interface can only directly address the first 3GB.

The latter restriction may be having an effect on the disk throughput. You can eliminate it as a possibility by (as an experiment!) rebooting with total_mem=3072 in config.txt. See if that makes any difference.

@ghost
Copy link

ghost commented Aug 25, 2020

How can I tell which silicon revision my BCM2711 is? Is it etched into the top of the package? All mine seem to be B0 - I'm guessing it's the B0 in the middle of this:

2711ZPKFSB06BOT

Do the chips with C0 silicon say C0 instead?

@pelwell
Copy link
Contributor

pelwell commented Aug 25, 2020

It's the penultimate 2 characters that matter: 2711ZPKFSB06COT

On a running system the easiest way to tell is to look at the declaration of the bus the SD card controller is on:

# B0
pi@raspberrypi:~$ od -An -tx1 /proc/device-tree/emmc2bus/dma-ranges
 00 00 00 00 c0 00 00 00 00 00 00 00 00 00 00 00
 40 00 00 00

# C0
pi@raspberrypi:~$ od -An -tx1 /proc/device-tree/emmc2bus/dma-ranges
 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 fc 00 00 00

@pelwell
Copy link
Contributor

pelwell commented Aug 25, 2020

As far as I know, all production 8GB units are fitted with C0s.

@bkev
Copy link

bkev commented Aug 25, 2020

That's a rev 1.1 4B with 4GB RAM running a recent kernel. The rev 1.1 boards where fitted with BCM2711B0 - the first production silicon - which had a few restrictions that were improved in the later C0 revision:

  1. The EMMC2 bus can only directly address the first 1GB.
  2. The PCIe interface can only directly address the first 3GB.

The latter restriction may be having an effect on the disk throughput. You can eliminate it as a possibility by (as an experiment!) rebooting with total_mem=3072 in config.txt. See if that makes any difference.

Thanks for the info.

So, my board not only has the USB-C power issue, it also can't access all of the memory?

Will the total_mem=3072 limit the board to 3Gb instead of 4Gb of memory?

@pelwell
Copy link
Contributor

pelwell commented Aug 25, 2020

It's a test - I'm trying to ascertain whether or not SWIOTLB is a factor or not. Yes it will limit the system to 3GB during the test.

@bkev
Copy link

bkev commented Aug 25, 2020

Hi @pelwell thanks for the info.

My Pi will be doing a dd tomorrow night as part of a cron job. I'll let it do it without me changing anything to see if it occurs again. If it does, I'll make the change and then let it do the dd again to see if it happens again and I will report back. This will probably be the end of next week though.

Thanks again.

@tempestnano
Copy link

tempestnano commented May 19, 2021

I confirm that this issue is still around in the recent kernels. Using only mounted samba shares (no local usb drives) and running an io intensive program like resilio-sync or transmission, I get the familiar oom errors despite gigabytes of free ram. I can't force a crash using loopback script mentioned earlier.
kernel: Linux LibreELEC 5.10.27 #1 SMP Sat Apr 17 00:41:27 CEST 2021 armv7l GNU/Linux

@wushilin
Copy link

wushilin commented May 19, 2021 via email

@tempestnano
Copy link

tempestnano commented May 19, 2021

What USB adapter are you using? I recently bought a Toshiba cavil disk it worked great. Can’t reproduce with dd on zfs for 100gb, speed tops at 70mbps on USB 3.0.

I was referring to a test without any local usb drives at all, all i/o was performed over a remote samba share. I can reproduce this error for both usb 3.0 mount and remote samba mount.

I don't believe that a simple dd will trigger this error. I think it has to be lots of small r/w operations. Something about caching and queues perhaps?

@wushilin
Copy link

wushilin commented May 19, 2021 via email

@pelwell
Copy link
Contributor

pelwell commented May 19, 2021

@tempestnano What is your gpu_mem set to?

@tempestnano
Copy link

@tempestnano What is your gpu_mem set to?

gpu_mem=76
I did notice in the past that, for me, oom errors were more frequent with a higher value.

@maxonthegit
Copy link

@P33M, comprehensive details are in this post. In short, conditions that increase the likeliness of triggering the OOM reaper vary across systems.

For example:

  • @The7Tycoon observed it in LibreELEC with conservative (default?) system settings (gpu_mem=76).
  • @tempestnano also observed it, but writing data to a virtual loopback block device was not enough for him to trigger the OOM reaper.
  • In my case, with Raspbian 10 (buster) and kernels 5.4 or 5.10, I could consistently trigger the OOM event by setting gpu_mem to a(n insanely) high value like 512 and using the test script alone: values below this threshold made my system (specs here) rock solid; values above made it nearly unusable, with plenty of free RAM still available.

Beware that developers do not deem gpu_mem as a root cause by itself, especially since using a dynamic split (CMA) is advised: instead, playing with gpu_mem may just help highlight an issue with some memory-related kernel subsystem.

Effectiveness of dd alone in triggering the issue is also a bit disputed, as it is unclear whether few large disk writes or lots of small I/O operations are equally effective. Like @wushilin, for me dd was more than enough (even if in a wider range of cases than USB-to-SATA alone).

@H34dl3ss
Copy link

H34dl3ss commented Jul 6, 2021

A google search led me to this issue as I'm experiencing the same on my RPi4.
I'm mounting an USB3 disk attached to the RPi via smb on a Ubuntu machine.
Then I'm copying using the mc. Transfer speeds are around 110-120 MB/s - all that the GBit Ethernet is capable of.
Very satisfying at first. Files are around 100GB each.
Interesting thing, all went smooth for about 7TB and then it started choking.
I can follow on a htop how Mem fills up and finally drops.
At the same time the kernellog sees:
[Di Jul 6 20:56:14 2021] Out of memory: Killed process 32341 (smbd) total-vm:6860224kB, anon-rss:3682892kB, file-rss:416kB, shmem-rss:1104kB, UID:1000 pgtables:8400kB oom_score_adj:0
[Di Jul 6 20:56:14 2021] oom_reaper: reaped process 32341 (smbd), now anon-rss:0kB, file-rss:0kB, shmem-rss:1104kB

Here is the data asked above:

$ grep Revision /proc/cpuinfo
Revision : c03111

$ uname -a
Linux Pi4 5.10.17-v8+ #1414 SMP PREEMPT Fri Apr 30 13:23:25 BST 2021 aarch64 GNU/Linux

$ vmstat
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
1 0 128000 53132 12444 2357484 1 16 1699 5327 82 102 8 12 74 6 0

$ lsusb
Bus 002 Device 002: ID 174c:55aa ASMedia Technology Inc. Name: ASM1051E SATA 6Gb/s bridge, ASM1053E SATA 6Gb/s bridge, ASM1153 SATA 3Gb/s bridge, ASM1153E SATA 6Gb/s bridge
Bus 002 Device 004: ID 0bc2:331a Seagate RSS LLC
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 003: ID 4971:1015 SimpleTech
Bus 001 Device 002: ID 2109:3431 VIA Labs, Inc. Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

@pelwell
Copy link
Contributor

pelwell commented Jul 6, 2021

Can you try adding total_mem=3072 in config.txt? It will convince your Pi it has 3GB memory (so not ideal), but it may have a positive impact on the problem. It could also make it worse by reducing the time until memory is exhausted, which makes this an interesting test.

@pelwell
Copy link
Contributor

pelwell commented Jul 6, 2021

(setting changed to lower case)

@H34dl3ss
Copy link

H34dl3ss commented Jul 8, 2021

Sorry for the delayed feedback.
I tried the mem-setting in config.txt. In htop I can see less available memory.
At first it looked promising but eventually the reaper kicked in again.
It took a bit longer, but the issue still persists.

@pelwell
Copy link
Contributor

pelwell commented Jul 8, 2021

OK - thanks. That's one theory to cross off the list.

@wushilin
Copy link

wushilin commented Jul 8, 2021 via email

@H34dl3ss
Copy link

H34dl3ss commented Jul 8, 2021

@ wushilin
If there was an issue with the USB adaptor of the drive, there would be an error in the kernel log.
I have tested numerous adaptors and know how that kind of errors look like.
There are no errors of that kind.
This is a different story.

@wushilin
Copy link

wushilin commented Jul 8, 2021 via email

@wushilin
Copy link

wushilin commented Jul 8, 2021 via email

@tempestnano
Copy link

I have triggered this without any usb drive on the 32-bit rpi4 using a second rpi4 (with a 64-bit kernel) and a network share over gigabit ethernet. It is somehow related to filesystem I/O, but not any hardware directly.

@H34dl3ss
Copy link

H34dl3ss commented Jul 8, 2021

As transfer via smb is no option anymore, I tried rsync and there is no such problem. Performance is mediocre though.
I found some people using netcat and gave it a go - it's running like a champ.
Full speed, no memory problem and also no comfort.

I guess @tempestnano has a point with the I/O issue. SMB is spawning a mass of processes while it runs the copy.

@wushilin
The drive we are talking about is connected via the Seagate Expansion Desk converter. The other drive that showed same issues is the SimpleTech converter that belongs to a Hitachi Touro enclosure.

@Anuskuss
Copy link

If using kodi on 5.10 kernel (includes any Kodi Matrix builds) on a Pi 4, then gpu_mem above the default (76M) is not required.
HEVC decoded frames are allocated from CMA.
76M gpu_mem is enough for BlueRay h264 decode.
3D textures are allocated from arm memory.

No. gpu_mem is a fixed at boot time carve out of a certain amount of memory (that resides at top of first 1GB a ram).
It is used for direct gpu allocations from some openmax/mmal operations like video decode, the legacy 3d driver (i.e. not using kms/fkms) and for arm side allocations using /dev/vcsm (for mmal operations using zero copy).

@popcornmix I have been experiencing some OOM errors as well and I'm thinking that decreasing gpu_mem will not solve the problem, but atleast delay it. I'm using a headless setup so I'm wondering if I could set gpu_mem to something small like 0. The only thing in my setup that even touches the GPU is v4l2 (ffmpeg). Is gpu_mem required in that case or is CMA enough? Jellyfin for example uses omx and recommends 320M.

@popcornmix
Copy link
Collaborator

You can't have 0 gpu_mem, the minimum is 16 (the gpu still handles the initial boot from sdcard and manages clocks and power).
If v4l2 is using hardware accelerated h264, then then default (76M which you get when unspecified) is sufficient.
If v4l2 is using hardware accelerated hevc then that uses cma, so no requirement on gpu mem.

@piadam
Copy link

piadam commented Aug 1, 2021

In the Raspberry Pi forum I recently discussed problems like Bus Errors, Kernel Panics etc., that I encountered using gpu_mem=16. I was adviced to use 32 as a minimum, which, indeed solved these problems. So I suggest to stop using 16 as a minimum.
Apart from that, I too experience OOM-killer-problems on my 4GB Pi4, that is being used as an rsync-/NFS-fileserver.
I have just changed some config.txt-settings, as adviced in this thread. Will let you know if (ever) I find the very setting that cures the problem.

16:03 nasberrypi: % grep Revision /proc/cpuinfo
Revision : c03112
16:08 nasberrypi: % uname -a
Linux nasberrypi 5.10.52-v7l+ #1440 SMP Tue Jul 27 09:55:21 BST 2021 armv7l GNU/Linux
16:08 nasberrypi: % vmstat
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
0 0 0 3644824 21796 121296 0 0 48 18 85 81 0 1 97 2 0
16:08 nasberrypi: % lsusb
Bus 002 Device 002: ID 0bc2:3322 Seagate RSS LLC SRD0NF2 [Expansion Desktop Drive]
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 008: ID 152d:0567 JMicron Technology Corp. / JMicron USA Technology Corp. JMS567 SATA 6Gb/s bridge
Bus 001 Device 007: ID 0bc2:331a Seagate RSS LLC
Bus 001 Device 009: ID 1058:1105 Western Digital Technologies, Inc. My Book Studio II
Bus 001 Device 002: ID 2109:3431 VIA Labs, Inc. Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

@samimasad
Copy link

there is fixes in #3981 which can be related , anyone have checked if the problem still exist with the fixes applied ?

@lv10wizard
Copy link

there is fixes in #3981 which can be related , anyone have checked if the problem still exist with the fixes applied ?

The fixes in #3981 did not resolve this issue for my rpi4b 8gb.

$ uname -a
Linux pi 5.10.59-v7l+ #1447 SMP Thu Aug 19 12:25:41 BST 2021 armv7l GNU/Linux

It still encountered an overzealous OOM reaper while writing to an externally powered usb3 external HDD via nfs:

$ less /var/log/syslog
-- snip --
Aug 22 17:34:36 pi kernel: [67344.322273] nfsd invoked oom-killer: gfp_mask=0xcc0(GFP_KERNEL), order=0, oom_score_adj=0
Aug 22 17:34:36 pi kernel: [67344.322286] CPU: 3 PID: 790 Comm: nfsd Tainted: G         C        5.10.59-v7l+ #1447
Aug 22 17:34:36 pi kernel: [67344.322289] Hardware name: BCM2711
Aug 22 17:34:36 pi kernel: [67344.322293] Backtrace: 
Aug 22 17:34:36 pi kernel: [67344.322311] [<c0b82824>] (dump_backtrace) from [<c0b82bb8>] (show_stack+0x20/0x24)
Aug 22 17:34:36 pi kernel: [67344.322317]  r7:ffffffff r6:00000000 r5:60000013 r4:c12e6b7c
Aug 22 17:34:36 pi kernel: [67344.322324] [<c0b82b98>] (show_stack) from [<c0b86fa4>] (dump_stack+0xcc/0xf8)
Aug 22 17:34:36 pi kernel: [67344.322331] [<c0b86ed8>] (dump_stack) from [<c0b85234>] (dump_header+0x64/0x208)
Aug 22 17:34:36 pi kernel: [67344.322336]  r10:c12051cc r9:00000cc0 r8:00000000 r7:c0e3b9d0 r6:c2c11200 r5:cd7d0000
Aug 22 17:34:36 pi kernel: [67344.322340]  r4:c7d2beb8 r3:f6b21248
Aug 22 17:34:36 pi kernel: [67344.322350] [<c0b851d0>] (dump_header) from [<c03b85c8>] (oom_kill_process+0x1b4/0x1c0)
Aug 22 17:34:36 pi kernel: [67344.322355]  r7:c0e3b9d0 r6:c7d2beb8 r5:cd7d0580 r4:cd7d0000
Aug 22 17:34:36 pi kernel: [67344.322362] [<c03b8414>] (oom_kill_process) from [<c03b9140>] (out_of_memory+0x2b8/0x390)
Aug 22 17:34:36 pi kernel: [67344.322367]  r7:c12085c0 r6:c1205048 r5:cd7d0000 r4:c7d2beb8
Aug 22 17:34:36 pi kernel: [67344.322375] [<c03b8e88>] (out_of_memory) from [<c040c7b0>] (__alloc_pages_nodemask+0x7ec/0x1184)
Aug 22 17:34:36 pi kernel: [67344.322380]  r7:c1337ed0 r6:00003400 r5:00016e5f r4:00000000
Aug 22 17:34:36 pi kernel: [67344.322388] [<c040bfc4>] (__alloc_pages_nodemask) from [<c0b6de30>] (svc_recv+0x80/0xa8c)
Aug 22 17:34:36 pi kernel: [67344.322393]  r10:ffffe000 r9:c6ff8000 r8:00000021 r7:c5d5d780 r6:c6ff8234 r5:00000023
Aug 22 17:34:36 pi kernel: [67344.322397]  r4:c6ff8000
Aug 22 17:34:36 pi kernel: [67344.322461] [<c0b6ddb0>] (svc_recv) from [<bf0b90e8>] (nfsd+0xdc/0x164 [nfsd])
Aug 22 17:34:36 pi kernel: [67344.322466]  r10:c4457cfc r9:c6ff8000 r8:c1320e40 r7:bf100bc4 r6:c3253800 r5:00057e40
Aug 22 17:34:36 pi kernel: [67344.322470]  r4:c6ff8000
Aug 22 17:34:36 pi kernel: [67344.322516] [<bf0b900c>] (nfsd [nfsd]) from [<c0245a34>] (kthread+0x170/0x174)
Aug 22 17:34:36 pi kernel: [67344.322521]  r9:c6ff8000 r8:bf0b900c r7:c7d2a000 r6:00000000 r5:c7b06900 r4:c6f81740
Aug 22 17:34:36 pi kernel: [67344.322530] [<c02458c4>] (kthread) from [<c02000ec>] (ret_from_fork+0x14/0x28)
Aug 22 17:34:36 pi kernel: [67344.322534] Exception stack(0xc7d2bfb0 to 0xc7d2bff8)
Aug 22 17:34:36 pi kernel: [67344.322539] bfa0:                                     00000000 00000000 00000000 00000000
Aug 22 17:34:36 pi kernel: [67344.322544] bfc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
Aug 22 17:34:36 pi kernel: [67344.322548] bfe0: 00000000 00000000 00000000 00000000 00000013 00000000
Aug 22 17:34:36 pi kernel: [67344.322554]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458c4
Aug 22 17:34:36 pi kernel: [67344.322557]  r4:c7b06900
Aug 22 17:34:36 pi kernel: [67344.322561] Mem-Info:
Aug 22 17:34:36 pi kernel: [67344.322572] active_anon:23430 inactive_anon:543398 isolated_anon:0
Aug 22 17:34:36 pi kernel: [67344.322572]  active_file:23636 inactive_file:272917 isolated_file:110
Aug 22 17:34:36 pi kernel: [67344.322572]  unevictable:4 dirty:129 writeback:0
Aug 22 17:34:36 pi kernel: [67344.322572]  slab_reclaimable:37243 slab_unreclaimable:9733
Aug 22 17:34:36 pi kernel: [67344.322572]  mapped:17281 shmem:5097 pagetables:3137 bounce:0
Aug 22 17:34:36 pi kernel: [67344.322572]  free:1081770 free_pcp:184 free_cma:79488
Aug 22 17:34:36 pi kernel: [67344.322581] Node 0 active_anon:93720kB inactive_anon:2173592kB active_file:94544kB inactive_file:1091668kB unevictable:16kB isolated(anon):0kB isolated(file):440kB mapped:69124kB dirty:516kB writeback:0kB shmem:20388kB writeback_tmp:0kB kernel_stack:4208kB all_unreclaimable? no
Aug 22 17:34:36 pi kernel: [67344.322591] DMA free:342932kB min:53248kB low:57344kB high:61440kB reserved_highatomic:4096KB active_anon:0kB inactive_anon:0kB active_file:30740kB inactive_file:896kB unevictable:0kB writepending:0kB present:786432kB managed:629484kB mlocked:0kB pagetables:1352kB bounce:0kB free_pcp:288kB local_pcp:260kB free_cma:317952kB
Aug 22 17:34:36 pi kernel: [67344.322596] lowmem_reserve[]: 0 0 7284 7284
Aug 22 17:34:36 pi kernel: [67344.322626] HighMem free:3984148kB min:512kB low:49044kB high:97576kB reserved_highatomic:0KB active_anon:93720kB inactive_anon:2173420kB active_file:63924kB inactive_file:1090120kB unevictable:16kB writepending:0kB present:7458816kB managed:7458816kB mlocked:16kB pagetables:11196kB bounce:0kB free_pcp:444kB local_pcp:0kB free_cma:0kB
Aug 22 17:34:36 pi kernel: [67344.322631] lowmem_reserve[]: 0 0 0 0
Aug 22 17:34:36 pi kernel: [67344.322658] DMA: 497*4kB (UEHC) 1202*8kB (UEHC) 698*16kB (UEHC) 41*32kB (UMEHC) 12*64kB (UHC) 10*128kB (HC) 3*256kB (C) 2*512kB (HC) 0*1024kB 2*2048kB (C) 76*4096kB (C) = 343316kB
Aug 22 17:34:36 pi kernel: [67344.322763] HighMem: 17789*4kB (UM) 72071*8kB (UM) 62270*16kB (UM) 31247*32kB (UM) 10931*64kB (UM) 1422*128kB (UM) 41*256kB (M) 9*512kB (UM) 7*1024kB (M) 7*2048kB (UM) 103*4096kB (M) = 3984044kB
Aug 22 17:34:36 pi kernel: [67344.322873] 295479 total pagecache pages
Aug 22 17:34:36 pi kernel: [67344.322886] 124 pages in swap cache
Aug 22 17:34:36 pi kernel: [67344.322892] Swap cache stats: add 15251, delete 15128, find 1623/3165
Aug 22 17:34:36 pi kernel: [67344.322897] Free swap  = 10064036kB
Aug 22 17:34:36 pi kernel: [67344.322902] Total swap = 10110372kB
Aug 22 17:34:36 pi kernel: [67344.322907] 2061312 pages RAM
Aug 22 17:34:36 pi kernel: [67344.322912] 1864704 pages HighMem/MovableOnly
Aug 22 17:34:36 pi kernel: [67344.322917] 39237 pages reserved
Aug 22 17:34:36 pi kernel: [67344.322922] 81920 pages cma reserved
Aug 22 17:34:36 pi kernel: [67344.322928] Tasks state (memory values in pages):
Aug 22 17:34:36 pi kernel: [67344.322933] [  pid  ]   uid  tgid total_vm      rss pgtables_bytes swapents oom_score_adj name
Aug 22 17:34:36 pi kernel: [67344.322959] [    155]     0   155     7402     4124   229376        5             0 systemd-journal
Aug 22 17:34:36 pi kernel: [67344.322968] [    170]     0   170     1139       21    32768       23             0 blkmapd
Aug 22 17:34:36 pi kernel: [67344.322978] [    194]     0   194     4551      593    49152       59         -1000 systemd-udevd
Aug 22 17:34:36 pi kernel: [67344.322994] [    453]     0   453      699       25    28672       10             0 rpc.idmapd
Aug 22 17:34:36 pi kernel: [67344.323001] [    461]   100   461     5606      868    57344        0             0 systemd-timesyn
Aug 22 17:34:36 pi kernel: [67344.323009] [    497] 65534   497     1080      485    36864        0             0 thd
Aug 22 17:34:36 pi kernel: [67344.323016] [    498]     0   498     3263      761    53248      135             0 systemd-logind
Aug 22 17:34:36 pi kernel: [67344.323023] [    499]   104   499     1637      710    36864        5          -900 dbus-daemon
Aug 22 17:34:36 pi kernel: [67344.323029] [    500]     0   500     6378      702    53248      129             0 rsyslogd
Aug 22 17:34:36 pi kernel: [67344.323036] [    502]   108   502     1473      622    32768       32             0 avahi-daemon
Aug 22 17:34:36 pi kernel: [67344.323043] [    503]     0   503      923      392    32768        7             0 alsactl
Aug 22 17:34:36 pi kernel: [67344.323050] [    506]     0   506     2686      498    49152       81             0 wpa_supplicant
Aug 22 17:34:36 pi kernel: [67344.323056] [    522]   108   522     1442       20    32768       43             0 avahi-daemon
Aug 22 17:34:36 pi kernel: [67344.323063] [    591]     0   591      534        1    28672       25             0 hciattach
Aug 22 17:34:36 pi kernel: [67344.323070] [    618]     0   618     2384      232    40960       92             0 bluetoothd
Aug 22 17:34:36 pi kernel: [67344.323077] [    625]     0   625     2751      254    45056      118             0 wpa_supplicant
Aug 22 17:34:36 pi kernel: [67344.323091] [    754]     0   754      792      370    32768      156             0 dhcpcd
Aug 22 17:34:36 pi kernel: [67344.323098] [    762]     0   762   231471     5373   176128      219          -999 containerd
Aug 22 17:34:36 pi kernel: [67344.323105] [    763]     0   763    12092     2040   126976        4             0 smbd
Aug 22 17:34:36 pi kernel: [67344.323112] [    764]   105   764     1678      599    45056        0             0 rpcbind
Aug 22 17:34:36 pi kernel: [67344.323119] [    765]     0   765     2700      766    45056        0         -1000 sshd
Aug 22 17:34:36 pi kernel: [67344.323126] [    766]     0   766     8315      924    90112     6175             0 rpc.mountd
Aug 22 17:34:36 pi kernel: [67344.323133] [    778]     0   778     3120      866    45056        0             0 sshd
Aug 22 17:34:36 pi kernel: [67344.323142] [    781]     0   781   247770     6703   249856      312          -500 dockerd
Aug 22 17:34:36 pi kernel: [67344.323151] [    804]     0   804     1995      605    36864        0             0 cron
Aug 22 17:34:36 pi kernel: [67344.323159] [    806]     0   806     6914      361    40960        2             0 rngd
Aug 22 17:34:36 pi kernel: [67344.323166] [    811]     0   811    11358     1301   114688       21             0 smbd-notifyd
Aug 22 17:34:36 pi kernel: [67344.323173] [    813]     0   813     1077      287    36864        0             0 agetty
Aug 22 17:34:36 pi kernel: [67344.323180] [    814]     0   814    11359     1229   114688       21             0 cleanupd
Aug 22 17:34:36 pi kernel: [67344.323187] [    836]     0   836    12089     1294   114688       16             0 lpqd
Aug 22 17:34:36 pi kernel: [67344.323193] [   1173]     0  1173   213278      371    77824       25          -500 docker-proxy
Aug 22 17:34:36 pi kernel: [67344.323201] [   1177]     0  1177   219857      395    90112       23          -500 docker-proxy
Aug 22 17:34:36 pi kernel: [67344.323207] [   1182]     0  1182   215583      416    90112        0          -500 docker-proxy
Aug 22 17:34:36 pi kernel: [67344.323214] [   1204]     0  1204   210909      420    73728        0          -500 docker-proxy
Aug 22 17:34:36 pi kernel: [67344.323221] [   1206]     0  1206   217632      230    98304        0          -500 docker-proxy
Aug 22 17:34:36 pi kernel: [67344.323227] [   1207]     0  1207   217632      260    77824        0          -500 docker-proxy
Aug 22 17:34:36 pi kernel: [67344.323234] [   1242]     0  1242   215583      243    94208        0          -500 docker-proxy
Aug 22 17:34:36 pi kernel: [67344.323241] [   1250]     0  1250   213278      231    81920        0          -500 docker-proxy
Aug 22 17:34:36 pi kernel: [67344.323248] [   1267]     0  1267   217568      416    81920        0          -500 docker-proxy
Aug 22 17:34:36 pi kernel: [67344.323255] [   1276]     0  1276   210909      252    69632        0          -500 docker-proxy
Aug 22 17:34:36 pi kernel: [67344.323262] [   1300]     0  1300   200529      896    53248        0          -998 containerd-shim
Aug 22 17:34:36 pi kernel: [67344.323268] [   1304]     0  1304   200705      887    49152        0          -998 containerd-shim
Aug 22 17:34:36 pi kernel: [67344.323275] [   1306]     0  1306   200705     1771    53248        5          -998 containerd-shim
Aug 22 17:34:36 pi kernel: [67344.323282] [   1366]     0  1366       49        1    24576        0             0 s6-svscan
Aug 22 17:34:36 pi kernel: [67344.323290] [   1367]     0  1367      332      203    28672        0             0 entry.sh
Aug 22 17:34:36 pi kernel: [67344.323297] [   1368]  1000  1368   130901    64993   815104      144             0 jellyfin
Aug 22 17:34:36 pi kernel: [67344.323304] [   1620]     0  1620       50        1    20480        0             0 s6-supervise
Aug 22 17:34:36 pi kernel: [67344.323311] [   1838]     0  1838       50        1    20480        0             0 s6-supervise
Aug 22 17:34:36 pi kernel: [67344.323318] [   1840]     0  1840      250        1    20480        0             0 sh
Aug 22 17:34:36 pi kernel: [67344.323325] [   1878]     0  1878   200529      862    49152        0          -998 containerd-shim
Aug 22 17:34:36 pi kernel: [67344.323332] [   1897]     0  1897   200705      801    53248        0          -998 containerd-shim
Aug 22 17:34:36 pi kernel: [67344.323339] [   1927]  1000  1927    87844    20279   487424      142             0 EmbyServer
Aug 22 17:34:36 pi kernel: [67344.323346] [   1985]     0  1985       50        1    20480        0             0 s6-svscan
Aug 22 17:34:36 pi kernel: [67344.323353] [   1988]     0  1988       50        1    20480        0             0 s6-svscan
Aug 22 17:34:36 pi kernel: [67344.323360] [   2244]     0  2244      329      193    28672        1             0 dante_wrapper.s
Aug 22 17:34:36 pi kernel: [67344.323368] [   2245]     0  2245      947      559    32768        0             0 openvpn
Aug 22 17:34:36 pi kernel: [67344.323375] [   2344]     0  2344       50        1    24576        0             0 s6-supervise
Aug 22 17:34:36 pi kernel: [67344.323382] [   2345]     0  2345       50        1    24576        0             0 s6-supervise
Aug 22 17:34:36 pi kernel: [67344.323389] [   2793]  1000  2793     3716     1143    57344        0             0 systemd
Aug 22 17:34:36 pi kernel: [67344.323396] [   2808]  1000  2808     4277      238    57344      258             0 (sd-pam)
Aug 22 17:34:36 pi kernel: [67344.323403] [   3068]  1000  3068     3120      629    45056        3             0 sshd
Aug 22 17:34:36 pi kernel: [67344.323410] [   3074]  1000  3074     2838      960    49152        0             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323417] [   3358]  1000  3358     1125       24    32768       49             0 ssh-agent
Aug 22 17:34:36 pi kernel: [67344.323424] [   3413]     0  3413     5702      228    36864        5             0 sockd
Aug 22 17:34:36 pi kernel: [67344.323431] [   4003]     0  4003       50        1    24576        0             0 s6-supervise
Aug 22 17:34:36 pi kernel: [67344.323438] [   4005]     0  4005       50        1    24576        0             0 s6-supervise
Aug 22 17:34:36 pi kernel: [67344.323444] [   4006]     0  4006      459      132    32768        0             0 bash
Aug 22 17:34:36 pi kernel: [67344.323452] [   4008]     0  4008      329      167    24576        0             0 crond
Aug 22 17:34:36 pi kernel: [67344.323459] [   4019]  1000  4019   417147   411001  3452928      967             0 transmission-da
Aug 22 17:34:36 pi kernel: [67344.323466] [   4047]     0  4047       50        1    20480        0             0 s6-supervise
Aug 22 17:34:36 pi kernel: [67344.323473] [   4048]     0  4048       50        1    24576        0             0 s6-supervise
Aug 22 17:34:36 pi kernel: [67344.323480] [   4053]     0  4053      459      127    28672        0             0 bash
Aug 22 17:34:36 pi kernel: [67344.323487] [   4057]     0  4057      329      164    24576        0             0 crond
Aug 22 17:34:36 pi kernel: [67344.323494] [   4077]  1000  4077    13520    12115   184320      403             0 transmission-da
Aug 22 17:34:36 pi kernel: [67344.323500] [   4121]  1000  4121     2009      627    36864        0             0 tmux: client
Aug 22 17:34:36 pi kernel: [67344.323507] [   4123]  1000  4123     2452     1076    45056        0             0 tmux: server
Aug 22 17:34:36 pi kernel: [67344.323514] [   4224]     0  4224     5627       42    36864        1             0 sockd
Aug 22 17:34:36 pi kernel: [67344.323521] [   4596]  1000  4596     2869      939    45056       36             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323528] [   4637]  1000  4637     2836      896    49152       63             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323535] [   4755]  1000  4755     2836      931    49152        0             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323541] [   4810]  1000  4810     2836      970    49152        0             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323548] [   4896]  1000  4896     2835      961    49152        0             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323555] [   4970]  1000  4970     2836      971    40960        0             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323562] [   5101]  1000  5101     2836      969    49152        0             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323568] [   5245]  1000  5245     2835      952    49152        1             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323575] [   5407]  1000  5407     2835      945    45056        1             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323582] [   5506]  1000  5506     2835      959    45056        1             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323588] [   5667]  1000  5667     2835      945    45056        1             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323596] [   5822]  1000  5822     2860      951    45056        1             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323602] [   5998]  1000  5998     2860      965    45056        1             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323609] [   6133]  1000  6133     2860      970    40960        1             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323617] [   6228]     0  6228     3120      864    45056        0             0 sshd
Aug 22 17:34:36 pi kernel: [67344.323624] [   6242]  1000  6242     3592     1542    57344        0             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323631] [   6325]  1000  6325     3120      612    45056        0             0 sshd
Aug 22 17:34:36 pi kernel: [67344.323638] [   6332]  1000  6332     2865      972    45056        0             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323645] [   6437]  1000  6437     2836      977    49152        1             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323653] [   6640]  1000  6640     2859      953    49152        1             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323660] [   6806]  1000  6806     2836      931    49152        1             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323667] [   6943]  1000  6943     2836      961    45056        0             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323674] [   7132]  1000  7132     2836      961    40960        0             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323681] [   7265]  1000  7265     2836      933    53248        0             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323688] [   7288]     0  7288     3120      871    49152        0             0 sshd
Aug 22 17:34:36 pi kernel: [67344.323696] [   7366]  1000  7366     3153      687    45056        0             0 sshd
Aug 22 17:34:36 pi kernel: [67344.323702] [   7370]  1000  7370     2865      973    49152        0             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323710] [   7402]  1000  7402     2859      949    49152        0             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323717] [   7509]  1000  7509     2859      959    49152        0             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323723] [   7670]  1000  7670     2972     1059    45056        0             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323730] [   9190]     0  9190     3120      871    49152        0             0 sshd
Aug 22 17:34:36 pi kernel: [67344.323737] [   9219]  1000  9219     3120      624    45056        0             0 sshd
Aug 22 17:34:36 pi kernel: [67344.323744] [   9231]  1000  9231     2863      977    49152        0             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323751] [   9555]     0  9555     3120      872    49152        0             0 sshd
Aug 22 17:34:36 pi kernel: [67344.323758] [   9590]  1000  9590     3120      637    45056        0             0 sshd
Aug 22 17:34:36 pi kernel: [67344.323765] [   9592]  1000  9592     2860      970    40960        0             0 zsh
Aug 22 17:34:36 pi kernel: [67344.323772] [  13094]     0 13094     2541      669    40960        0             0 sudo
Aug 22 17:34:36 pi kernel: [67344.323779] [  13127]  1000 13127     2046      687    45056        1             0 htop
Aug 22 17:34:36 pi kernel: [67344.323786] [  13931]     0 13931     1751      525    45056        0             0 watch
Aug 22 17:34:36 pi kernel: [67344.323792] [  14155]  1000 14155     2009      636    40960        0             0 tmux: client
Aug 22 17:34:36 pi kernel: [67344.323799] [  14555]  1000 14555     1624      425    36864        0             0 tail
Aug 22 17:34:36 pi kernel: [67344.323806] [  14556]  1000 14556     1839      476    40960        0             0 grep
Aug 22 17:34:36 pi kernel: [67344.323812] [  14630]  1000 14630     1624      396    40960        0             0 tail
Aug 22 17:34:36 pi kernel: [67344.323819] [  14631]  1000 14631     1896      504    40960        0             0 grep
Aug 22 17:34:36 pi kernel: [67344.323825] [  14850]  1000 14850     2009      629    40960        0             0 tmux: client
Aug 22 17:34:36 pi kernel: [67344.323832] [  14869]  1000 14869    45413    22697   286720       53             0 newsboat
Aug 22 17:34:36 pi kernel: [67344.323839] [  15435]  1000 15435     2009      663    36864        0             0 tmux: client
Aug 22 17:34:36 pi kernel: [67344.323846] [  15569]     0 15569   200769      971    53248        0          -998 containerd-shim
Aug 22 17:34:36 pi kernel: [67344.323852] [  15594]  1000 15594     7571     2836    73728        7             0 irssi
Aug 22 17:34:36 pi kernel: [67344.323859] [  17341]  1000 17341     1650      331    40960        0             0 cat
Aug 22 17:34:36 pi kernel: [67344.323866] [  17385]  1000 17385   231912     3134   196608        0             0 docker
Aug 22 17:34:36 pi kernel: [67344.323873] [  24738]  1001 24738    22469     2318   192512        3             0 smbd
Aug 22 17:34:36 pi kernel: [67344.323880] [  30311]     0 30311     5749       94    36864      108             0 sockd
Aug 22 17:34:36 pi kernel: [67344.323887] [  30312]     0 30312     5749       94    36864      108             0 sockd
Aug 22 17:34:36 pi kernel: [67344.323894] [  30313]     0 30313     5749       94    36864      108             0 sockd
Aug 22 17:34:36 pi kernel: [67344.323902] [  30314]     0 30314     5749       94    36864      108             0 sockd
Aug 22 17:34:36 pi kernel: [67344.323909] [  30769]     0 30769     5749      138    36864       64             0 sockd
Aug 22 17:34:36 pi kernel: [67344.323916] [  30775]     0 30775     5749      198    36864        4             0 sockd
Aug 22 17:34:36 pi kernel: [67344.323923] [  30835]     0 30835     5749      199    36864        3             0 sockd
Aug 22 17:34:36 pi kernel: [67344.323930] [  30840]     0 30840     5749      198    36864        4             0 sockd
Aug 22 17:34:36 pi kernel: [67344.323937] [  30845]     0 30845     5749      155    36864       47             0 sockd
Aug 22 17:34:36 pi kernel: [67344.323944] [  30855]     0 30855     5749      138    36864       64             0 sockd
Aug 22 17:34:36 pi kernel: [67344.323950] [   3945]     0  3945     5749      266    36864        5             0 sockd
Aug 22 17:34:36 pi kernel: [67344.323957] [   3951]     0  3951     5749      293    36864        3             0 sockd
Aug 22 17:34:36 pi kernel: [67344.323964] [   4694]     0  4694     5749      293    36864        3             0 sockd
Aug 22 17:34:36 pi kernel: [67344.323970] [   4700]     0  4700     5749      293    36864        3             0 sockd
Aug 22 17:34:36 pi kernel: [67344.323977] [  10042]     0 10042     5876      398    69632        3             0 sockd
Aug 22 17:34:36 pi kernel: [67344.323984] [  10043]     0 10043     5749      293    36864        3             0 sockd
Aug 22 17:34:36 pi kernel: [67344.323991] [  10044]     0 10044     5999      438    40960        3             0 sockd
Aug 22 17:34:36 pi kernel: [67344.323998] [  10049]     0 10049     5834      325    40960        3             0 sockd
Aug 22 17:34:36 pi kernel: [67344.324004] [  10050]     0 10050     5749      293    36864        3             0 sockd
Aug 22 17:34:36 pi kernel: [67344.324017] [  26118]     0 26118     1751       42    32768        0             0 watch
Aug 22 17:34:36 pi kernel: [67344.324024] [  26119]     0 26119      485       87    32768        0             0 sh
Aug 22 17:34:36 pi kernel: [67344.324032] oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0,global_oom,task_memcg=/,task=transmission-da,pid=4019,uid=1000
Aug 22 17:34:36 pi kernel: [67344.324102] Out of memory: Killed process 4019 (transmission-da) total-vm:1668588kB, anon-rss:1641776kB, file-rss:2228kB, shmem-rss:0kB, UID:1000 pgtables:3372kB oom_score_adj:0
Aug 22 17:35:02 pi kernel: [67370.104233] oom_reaper: reaped process 4019 (transmission-da), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
-- snip --

@christroutner
Copy link

I wanted to drop some words and links that will hopefully help other users in with my issue find this via Google. I came to this thread in a roundabout way via this Raspberry Pi Forum post.

I was trying to format two 4TB USB3.0 hard drives in a RAID1 array with my Pi4. I was able to create the RAID array, but at the point I tried to create the filesystem with this command:

  • sudo mkfs.ext4 /dev/md0p1

I would get this error:

  • Creating journal (262144 blocks): Killed

I followed the tip in this thread from @jozsefDevs:

Okay, so for me this issue is resolved. I just set arm_64bit=1 into /boot/config.txt and my Pi runs since 8 days without any OOM reaping. Again, this is the Pi4 / 4GB version.

After rebooting the Pi, I was able to run mkfs.ext4.

@tempestnano
Copy link

I wanted to drop some words and links that will hopefully help other users in with my issue find this via Google. I came to this thread in a roundabout way via this Raspberry Pi Forum post.

I was trying to format two 4TB USB3.0 hard drives in a RAID1 array with my Pi4. I was able to create the RAID array, but at the point I tried to create the filesystem with this command:

  • sudo mkfs.ext4 /dev/md0p1

I would get this error:

  • Creating journal (262144 blocks): Killed

I followed the tip in this thread from @jozsefDevs:

Okay, so for me this issue is resolved. I just set arm_64bit=1 into /boot/config.txt and my Pi runs since 8 days without any OOM reaping. Again, this is the Pi4 / 4GB version.

After rebooting the Pi, I was able to run mkfs.ext4.

This does absolutely fix the issue, but it persists for those stuck on the 32-bit kernel (in my case, Libreelec).

@popcornmix
Copy link
Collaborator

This does absolutely fix the issue, but it persists for those stuck on the 32-bit kernel (in my case, Libreelec).

LibreELEC has switched to 64-bit kernel. See: LibreELEC/LibreELEC.tv#5507

@LevitatingBusinessMan
Copy link

LevitatingBusinessMan commented Jul 2, 2024

I faced this issue as well. During large downloads, the OOM reaper would reap basically all of my load bearing daemons. systemd-journal would even show warnings about flushing its caches due to tight memory constraints.

I installed the 64 bit kernel and started using that, now I have none of these issues. My downloads are also much faster and the kernel now seems to correctly fill its cache (before the use of cached memory was all over the place).

image

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests