kworker page allocation failure

[Marcool]

Hi all,

First of all, this is a cross-post from the raspberry pi linux kernel Github issue tracker.

When trying to transfer a large file over the network to my Raspberry Pi, I am seeing a kworker page allocation failure from kcryptd kcryptd_crypt workqueue. The raspberry pi HDD is encrypted using luks.

$this->bbcode_second_pass_code('', '# wget http://example.com/a_large_file')

$this->bbcode_second_pass_code('', '
$ grep home /etc/fstab
/dev/mapper/home /home ext4 defaults,nofail,noatime,x-systemd.automount,x-systemd.device-timeout=10 0 2

$ grep home /etc/crypttab
home UUID=e1639ef1-0860-4ef7-8583-bf9a3ac63ed2 [KEY] luks

$ blkid | grep "e1639ef1"
/dev/sda3: UUID="e1639ef1-0860-4ef7-8583-bf9a3ac63ed2" TYPE="crypto_LUKS" PARTLABEL="Linux filesystem" PARTUUID="e0d8cfe7-d259-4bf0-aaf3-966477f9fd1d"

$ ethtool -k eth0
Features for eth0:
rx-checksumming: on
tx-checksumming: on
tx-checksum-ipv4: on
tx-checksum-ip-generic: off [fixed]
tx-checksum-ipv6: off [fixed]
tx-checksum-fcoe-crc: off [fixed]
tx-checksum-sctp: off [fixed]
scatter-gather: off
tx-scatter-gather: off [fixed]
tx-scatter-gather-fraglist: off [fixed]
tcp-segmentation-offload: off
tx-tcp-segmentation: off [fixed]
tx-tcp-ecn-segmentation: off [fixed]
tx-tcp-mangleid-segmentation: off [fixed]
tx-tcp6-segmentation: off [fixed]
udp-fragmentation-offload: off
generic-segmentation-offload: off [requested on]
generic-receive-offload: on
large-receive-offload: off [fixed]
rx-vlan-offload: off [fixed]
tx-vlan-offload: off [fixed]
ntuple-filters: off [fixed]
receive-hashing: off [fixed]
highdma: off [fixed]
rx-vlan-filter: off [fixed]
vlan-challenged: off [fixed]
tx-lockless: off [fixed]
netns-local: off [fixed]
tx-gso-robust: off [fixed]
tx-fcoe-segmentation: off [fixed]
tx-gre-segmentation: off [fixed]
tx-gre-csum-segmentation: off [fixed]
tx-ipxip4-segmentation: off [fixed]
tx-ipxip6-segmentation: off [fixed]
tx-udp_tnl-segmentation: off [fixed]
tx-udp_tnl-csum-segmentation: off [fixed]
tx-gso-partial: off [fixed]
tx-sctp-segmentation: off [fixed]
tx-esp-segmentation: off [fixed]
fcoe-mtu: off [fixed]
tx-nocache-copy: off
loopback: off [fixed]
rx-fcs: off [fixed]
rx-all: off [fixed]
tx-vlan-stag-hw-insert: off [fixed]
rx-vlan-stag-hw-parse: off [fixed]
rx-vlan-stag-filter: off [fixed]
l2-fwd-offload: off [fixed]
hw-tc-offload: off [fixed]
esp-hw-offload: off [fixed]
esp-tx-csum-hw-offload: off [fixed]
rx-udp_tunnel-port-offload: off [fixed]
')


Withing a few seconds I get a "kworker/u9:0: page allocation failure" in the logs (see rest of kernel message below).
Other than that the transfer seems to function fine.

Here is some background information:

Raspberry Pi Pi3B+

$this->bbcode_second_pass_code('', '
$ cat /etc/os-release
NAME="Arch Linux ARM"
ID=archarm
ID_LIKE=arch
PRETTY_NAME="Arch Linux ARM"
ANSI_COLOR="0;36"
HOME_URL="http://archlinuxarm.org/"
SUPPORT_URL="https://archlinuxarm.org/forum"
BUG_REPORT_URL="https://github.com/archlinuxarm/PKGBUILDs/issues"

$ vcgencmd version
Dec 4 2018 16:50:03
Copyright (c) 2012 Broadcom
version 1f3414729f43ef3b977a910a0d811a759562e1cf (clean) (release)

$ uname -a
Linux [HOST] 4.14.85-1-ARCH #1 SMP Wed Dec 5 01:54:24 UTC 2018 armv7l GNU/Linux
')

Logs:
$this->bbcode_second_pass_code('', '
Dec 07 16:58:11 [HOST] kernel: kworker/u9:2: page allocation failure: order:0, mode:0x1080020(GFP_ATOMIC), nodemask=(null)
Dec 07 16:58:11 [HOST] kernel: kworker/u9:2 cpuset=/ mems_allowed=0
Dec 07 16:58:11 [HOST] kernel: CPU: 0 PID: 24617 Comm: kworker/u9:2 Tainted: G C 4.14.85-1-ARCH #1
Dec 07 16:58:11 [HOST] kernel: Hardware name: BCM2835
Dec 07 16:58:11 [HOST] kernel: Workqueue: kcryptd kcryptd_crypt
Dec 07 16:58:11 [HOST] kernel: [<8010eda8>] (unwind_backtrace) from [<8010b878>] (show_stack+0x10/0x14)
Dec 07 16:58:11 [HOST] kernel: [<8010b878>] (show_stack) from [<80a82bbc>] (dump_stack+0x9c/0xc8)
Dec 07 16:58:11 [HOST] kernel: [<80a82bbc>] (dump_stack) from [<80248a90>] (warn_alloc+0xd0/0x1a0)
Dec 07 16:58:11 [HOST] kernel: [<80248a90>] (warn_alloc) from [<80249b4c>] (__alloc_pages_nodemask+0xf54/0x10ac)
Dec 07 16:58:11 [HOST] kernel: [<80249b4c>] (__alloc_pages_nodemask) from [<80249ea8>] (page_frag_alloc+0x168/0x198)
Dec 07 16:58:11 [HOST] kernel: [<80249ea8>] (page_frag_alloc) from [<80976190>] (__netdev_alloc_skb+0x90/0x10c)
Dec 07 16:58:11 [HOST] kernel: [<80976190>] (__netdev_alloc_skb) from [<8081b654>] (rx_submit+0xc8/0x218)
Dec 07 16:58:11 [HOST] kernel: [<8081b654>] (rx_submit) from [<8081bbbc>] (rx_complete+0x1a0/0x218)
Dec 07 16:58:11 [HOST] kernel: [<8081bbbc>] (rx_complete) from [<80827b88>] (__usb_hcd_giveback_urb+0x7c/0x150)
Dec 07 16:58:11 [HOST] kernel: [<80827b88>] (__usb_hcd_giveback_urb) from [<80850d78>] (completion_tasklet_func+0x78/0xbc)
Dec 07 16:58:11 [HOST] kernel: [<80850d78>] (completion_tasklet_func) from [<801351fc>] (tasklet_hi_action+0x64/0xf8)
Dec 07 16:58:11 [HOST] kernel: [<801351fc>] (tasklet_hi_action) from [<8010157c>] (__do_softirq+0xd4/0x32c)
Dec 07 16:58:11 [HOST] kernel: [<8010157c>] (__do_softirq) from [<80134e60>] (irq_exit+0x8c/0x148)
Dec 07 16:58:11 [HOST] kernel: [<80134e60>] (irq_exit) from [<801852b4>] (__handle_domain_irq+0x58/0xb8)
Dec 07 16:58:11 [HOST] kernel: [<801852b4>] (__handle_domain_irq) from [<80a9ccf8>] (__irq_svc+0x58/0x74)
Dec 07 16:58:11 [HOST] kernel: [<80a9ccf8>] (__irq_svc) from [<80123a34>] (SRM0+0x164/0x4a0)
Dec 07 16:58:11 [HOST] kernel: Mem-Info:
Dec 07 16:58:11 [HOST] kernel: active_anon:31867 inactive_anon:36562 isolated_anon:0
Dec 07 16:58:11 [HOST] kernel: Node 0 active_anon:127468kB inactive_anon:146248kB active_file:239656kB inactive_file:318536kB unevictable:1704kB isolated(anon):0kB isolated(file):0kB mapped:123272kB dirty:14828kB writeback:26480kB shmem:22648kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
Dec 07 16:58:11 [HOST] kernel: Normal free:5984kB min:3872kB low:4840kB high:5808kB active_anon:127468kB inactive_anon:146248kB active_file:239780kB inactive_file:318436kB unevictable:1704kB writepending:41208kB present:983040kB managed:958388kB mlocked:1704kB kernel_stack:2800kB pagetables:8796kB bounce:0kB free_pcp:1244kB local_pcp:100kB free_cma:2080kB
Dec 07 16:58:11 [HOST] kernel: lowmem_reserve[]: 0 0
Dec 07 16:58:11 [HOST] kernel: Normal: 6*4kB (HC) 65*8kB (HC) 37*16kB (HC) 31*32kB (HC) 13*64kB (HC) 4*128kB (H) 5*256kB (H) 2*512kB (H) 0*1024kB 0*2048kB 0*4096kB = 5776kB
Dec 07 16:58:11 [HOST] kernel: 148743 total pagecache pages
Dec 07 16:58:11 [HOST] kernel: 3191 pages in swap cache
Dec 07 16:58:11 [HOST] kernel: Swap cache stats: add 102557, delete 99366, find 390561/410524
Dec 07 16:58:11 [HOST] kernel: Free swap = 1905048kB
Dec 07 16:58:11 [HOST] kernel: Total swap = 2097148kB
Dec 07 16:58:11 [HOST] kernel: 245760 pages RAM
Dec 07 16:58:11 [HOST] kernel: 0 pages HighMem/MovableOnly
Dec 07 16:58:11 [HOST] kernel: 6163 pages reserved
Dec 07 16:58:11 [HOST] kernel: 2048 pages cma reserved
')

Please let me know if any more information is required. I have explored the various threads in the issue tracker related to page allocation failures, and I'm not seeing anything exactly comparable, so I wonder if there might be a separate issue here. Not sure what might make this system specific apart from the fact the file is being written to an encrypted drive…
Thanks all for you excellent work adapting the kernel to the Pi, and for a great piece of hardware!
Regards,
Mark.

[nsollars]

Everything with this points to memory ( either not enough of it ) or when the System is underload alot of I/O ( File / Streaming Video ), How much usuable memory do you have with the OS and what nots you have there?, remember the Pi only has 1GB which is really on thin ice these days.

Do you see any CPU throttling during your copies as the system also is encrypting as you pointed out.

[Marcool]

Hi nsollars, no the ram is far from being used up. This is a headless server and there is barely 200Mb wired (in the "used" column of free -h).
No CPU throttling is apparent…