From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-5.7 required=3.0 tests=BAYES_00,DKIM_SIGNED, DKIM_VALID,DKIM_VALID_AU,HEADER_FROM_DIFFERENT_DOMAINS,MAILING_LIST_MULTI, SPF_HELO_NONE,SPF_PASS,URIBL_BLOCKED autolearn=no autolearn_force=no version=3.4.0 Received: from mail.kernel.org (mail.kernel.org [198.145.29.99]) by smtp.lore.kernel.org (Postfix) with ESMTP id AD2C3C433DB for ; Mon, 1 Feb 2021 11:26:48 +0000 (UTC) Received: from kanga.kvack.org (kanga.kvack.org [205.233.56.17]) by mail.kernel.org (Postfix) with ESMTP id 0AB0764D90 for ; Mon, 1 Feb 2021 11:26:47 +0000 (UTC) DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org 0AB0764D90 Authentication-Results: mail.kernel.org; dmarc=fail (p=reject dis=none) header.from=uplinklabs.net Authentication-Results: mail.kernel.org; spf=pass smtp.mailfrom=owner-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix) id 95EA66B0072; Mon, 1 Feb 2021 06:26:47 -0500 (EST) Received: by kanga.kvack.org (Postfix, from userid 40) id 90EC66B0075; Mon, 1 Feb 2021 06:26:47 -0500 (EST) X-Delivered-To: int-list-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix, from userid 63042) id 84C366B0078; Mon, 1 Feb 2021 06:26:47 -0500 (EST) X-Delivered-To: linux-mm@kvack.org Received: from forelay.hostedemail.com (smtprelay0119.hostedemail.com [216.40.44.119]) by kanga.kvack.org (Postfix) with ESMTP id 6F5706B0072 for ; Mon, 1 Feb 2021 06:26:47 -0500 (EST) Received: from smtpin25.hostedemail.com (10.5.19.251.rfc1918.com [10.5.19.251]) by forelay02.hostedemail.com (Postfix) with ESMTP id 2D66D3631 for ; Mon, 1 Feb 2021 11:26:47 +0000 (UTC) X-FDA: 77769471654.25.group31_1a0ed71275c1 Received: from filter.hostedemail.com (10.5.16.251.rfc1918.com [10.5.16.251]) by smtpin25.hostedemail.com (Postfix) with ESMTP id E4C031804E3C1 for ; Mon, 1 Feb 2021 11:26:46 +0000 (UTC) X-HE-Tag: group31_1a0ed71275c1 X-Filterd-Recvd-Size: 9361 Received: from mail2.protonmail.ch (mail2.protonmail.ch [185.70.40.22]) by imf32.hostedemail.com (Postfix) with ESMTP for ; Mon, 1 Feb 2021 11:26:45 +0000 (UTC) Date: Mon, 01 Feb 2021 11:26:40 +0000 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=uplinklabs.net; s=protonmail3; t=1612178803; bh=D9L9nkcj7qr5x2gXhfoeXRaTU9mbRWpssuMIlDn9xMY=; h=Date:To:From:Reply-To:Subject:From; b=XA2Nq5XQ15zceHq8xsut6JRglqBj2RbDYqnVCRk/sWhJ27zCr5uXgmM60rqbdJLvT G4POgyNHcRuT2aSObG32VG2fSe7v8mRI7LEaVzWNy3EPddVPYNfaeu40LUHcZZT0Nr oKbeu4HE4BNVW0ll6Wx8oOrz6MH6T5pOHA4+O+9ZVDccUoVR4eiOyzUPGm9hDcHyQY orZHIlXwX4UzjUQ/qUQTBS/QNbxmgFYaCIpCbU349HC5VFQpq9Eav2LWNMYBY0QIfJ 3liTu/MknCPzpELAJdCETznopV4MGIINTcDcjFzltauZyPvQYPiTEEeD9skR55vD1v iCS0Py/Lwfeqw== To: "linux-mm@kvack.org" From: Steven Noonan Reply-To: Steven Noonan Subject: "cat /proc/sys/kernel/random/entropy_avail" sometimes causes page allocation failure Message-ID: MIME-Version: 1.0 Content-Type: multipart/signed; protocol="application/pgp-signature"; micalg=pgp-sha256; boundary="---------------------56369eeff82fc88f89512ee2d078f35d"; charset=utf-8 X-Bogosity: Ham, tests=bogofilter, spamicity=0.000000, version=1.2.4 Sender: owner-linux-mm@kvack.org Precedence: bulk X-Loop: owner-majordomo@kvack.org List-ID: This is an OpenPGP/MIME signed message (RFC 4880 and 3156) -----------------------56369eeff82fc88f89512ee2d078f35d Content-Type: multipart/mixed;boundary=---------------------e8dcaddd6b4d682d4fa53eb8adedb0fc -----------------------e8dcaddd6b4d682d4fa53eb8adedb0fc Content-Transfer-Encoding: quoted-printable Content-Type: text/plain;charset=utf-8 (Please CC me on replies, I'm not subscribed to the list.) I started seeing this problem several months ago, but after some Google se= arches I concluded that someone had already root caused and fixed it, and = I just needed to wait for a newer kernel to come along: https://www.spinics.net/lists/linux-mm/msg226311.html But it turns out this has not yet been fixed, even in 5.10.10. Also, while= it used to be logged as an order:5 allocation it's now an order:6 allocat= ion for some reason. It only happens rarely (anywhere from once per day to= once per week), but it's kind of scary to check the kernel log and see th= is: [569537.153097] cat: page allocation failure: order:6, mode:0x40dc0(GFP_KE= RNEL|__GFP_COMP|__GFP_ZERO), nodemask=3D(null),cpuset=3D/,mems_allowed=3D0 [569537.153104] CPU: 1 PID: 3153417 Comm: cat Tainted: P S IO = 5.10.10-1-hsw #1 [569537.153105] Hardware name: ASUSTeK COMPUTER INC. P10S-M WS Series/P10S= -M WS Series, BIOS 4503 07/23/2019 [569537.153106] Call Trace: [569537.153111] dump_stack+0x58/0x6b [569537.153113] warn_alloc.cold+0x78/0xdc [569537.153116] ? __alloc_pages_direct_compact+0x15f/0x170 [569537.153117] __alloc_pages_slowpath.constprop.0+0xc4e/0xc70 [569537.153120] __alloc_pages_nodemask+0x2de/0x310 [569537.153121] kmalloc_order+0x25/0x80 [569537.153122] kmalloc_order_trace+0x17/0x80 [569537.153125] proc_sys_call_handler+0xb8/0x250 [569537.153127] new_sync_read+0x10f/0x190 [569537.153128] vfs_read+0x147/0x1a0 [569537.153130] ksys_read+0x5f/0xe0 [569537.153131] do_syscall_64+0x2d/0x70 [569537.153134] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [569537.153135] RIP: 0033:0x7fcc21ef92b2 [569537.153137] Code: c0 e9 b2 fe ff ff 50 48 8d 3d d2 2a 0a 00 e8 e5 ec 0= 1 00 0f 1f 44 00 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 0f 05 = <48> 3d 00 f0 ff ff 77 56 c3 0f 1f 44 00 00 48 83 ec 28 48 89 54 24 [569537.153138] RSP: 002b:00007ffcfbcc5c88 EFLAGS: 00000246 ORIG_RAX: 0000= 000000000000 [569537.153140] RAX: ffffffffffffffda RBX: 0000000000020000 RCX: 00007fcc2= 1ef92b2 [569537.153140] RDX: 0000000000020000 RSI: 00007fcc21ff8000 RDI: 000000000= 0000003 [569537.153141] RBP: 00007fcc21ff8000 R08: 00007fcc21ff7010 R09: 000000000= 0000000 [569537.153142] R10: 0000000000000022 R11: 0000000000000246 R12: 0000556e9= 9b70c00 [569537.153142] R13: 0000000000000003 R14: 0000000000020000 R15: 000000000= 0020000 [569537.153144] Mem-Info: [569537.153146] active_anon:50924 inactive_anon:1715988 isolated_anon:0 active_file:163427 inactive_file:104041 isolated_file:0 unevictable:3247 dirty:5825 writeback:0 slab_reclaimable:39566 slab_unreclaimable:1760175 mapped:49406 shmem:17850 pagetables:10611 bounce:0 free:1060578 free_pcp:0 free_cma:0 [569537.153149] Node 0 active_anon:203696kB inactive_anon:6863952kB active= _file:653708kB inactive_file:416164kB unevictable:12988kB isolated(anon):0= kB isolated(file):0kB mapped:197624kB dirty:23300kB writeback:0kB shmem:71= 400kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 0kB writeback_tmp:0kB = kernel_stack:18112kB all_unreclaimable? no [569537.153151] Node 0 DMA free:11800kB min:24kB low:36kB high:48kB reserv= ed_highatomic:0KB active_anon:0kB inactive_anon:0kB active_file:0kB inacti= ve_file:0kB unevictable:0kB writepending:0kB present:15984kB managed:15896= kB mlocked:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_c= ma:0kB [569537.153153] lowmem_reserve[]: 0 1810 64139 64139 64139 [569537.153156] Node 0 DMA32 free:252476kB min:3208kB low:5076kB high:6944= kB reserved_highatomic:0KB active_anon:756kB inactive_anon:124844kB active= _file:2120kB inactive_file:180kB unevictable:0kB writepending:0kB present:= 1937436kB managed:1871900kB mlocked:0kB pagetables:8kB bounce:0kB free_pcp= :0kB local_pcp:0kB free_cma:0kB [569537.153158] lowmem_reserve[]: 0 0 62329 62329 62329 [569537.153160] Node 0 Normal free:3978036kB min:109404kB low:173232kB hig= h:237060kB reserved_highatomic:2048KB active_anon:202940kB inactive_anon:6= 739108kB active_file:651588kB inactive_file:415984kB unevictable:12988kB w= ritepending:23076kB present:65011712kB managed:63831896kB mlocked:11176kB = pagetables:42436kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB [569537.153162] lowmem_reserve[]: 0 0 0 0 0 [569537.153164] Node 0 DMA: 2*4kB (U) 2*8kB (U) 2*16kB (U) 3*32kB (U) 2*64= kB (U) 2*128kB (U) 0*256kB 0*512kB 1*1024kB (U) 1*2048kB (M) 2*4096kB (M) = =3D 11800kB [569537.153171] Node 0 DMA32: 3738*4kB (UME) 2341*8kB (UME) 1719*16kB (UME= ) 943*32kB (UME) 443*64kB (UME) 19*128kB (UME) 108*256kB (UME) 169*512kB (= UM) 8*1024kB (UM) 4*2048kB (UM) 0*4096kB =3D 252704kB [569537.153179] Node 0 Normal: 81071*4kB (UMEH) 112101*8kB (UMEH) 101108*1= 6kB (UMEH) 34297*32kB (UMEH) 660*64kB (UME) 0*128kB 0*256kB 0*512kB 0*1024= kB 0*2048kB 0*4096kB =3D 3978564kB [569537.153185] Node 0 hugepages_total=3D0 hugepages_free=3D0 hugepages_su= rp=3D0 hugepages_size=3D1048576kB [569537.153186] Node 0 hugepages_total=3D64 hugepages_free=3D51 hugepages_= surp=3D64 hugepages_size=3D2048kB [569537.153186] 298118 total pagecache pages [569537.153197] 14242 pages in swap cache [569537.153198] Swap cache stats: add 165298, delete 151079, find 10932118= /10944726 [569537.153199] Free swap =3D 100129528kB [569537.153199] Total swap =3D 100663288kB [569537.153200] 16741283 pages RAM [569537.153201] 0 pages HighMem/MovableOnly [569537.153201] 311360 pages reserved [569537.153202] 0 pages hwpoisoned I used sysdig to figure out what 'cat' was trying to read when it failed, = via: # sysdig -p "%12user.name %6proc.pid %12proc.name %fd.name %evt.args" 'evt= .type=3Dread and evt.failed=3Dtrue and proc.name=3Dcat' The relevant one was this: nobody 315341 cat /proc/sys/kernel/random/entropy_avail res= =3D-12(ENOMEM) data=3D Which I believe is a munin script gathering a bunch of data for graphs (mu= nin-node runs as "nobody", uses shell scripts for its data gathering, and = one of the plugins tracks entropy_avail, so that would seem to be the guil= ty party). Any idea why it's trying to do an order:6 allocation for just a simple rea= d of entropy_avail? Based on the stack trace I'm guessing this isn't owned= by the "random" driver maintainers, it seems to be a more general issue w= ith memory allocations while reading from procfs. -----------------------e8dcaddd6b4d682d4fa53eb8adedb0fc-- -----------------------56369eeff82fc88f89512ee2d078f35d Content-Type: application/pgp-signature; name="signature.asc" Content-Description: OpenPGP digital signature Content-Disposition: attachment; filename="signature.asc" -----BEGIN PGP SIGNATURE----- Version: ProtonMail wsBzBAEBCAAGBQJgF+VkACEJEH6stEunsw25FiEE+NX4GY3rBwMVZRqQfqy0 S6ezDbmrDAf+IODsx8zcxMzDqyMLNFzQOOr069qd80CWvIdGFg7S3Yn0WdGa BB5UZ2SBik9DREnjbMhgn8oMzBb8EXVbXfy8/HVhKxAeJcBHtjw2EeVZcXSp BvvwRvDgYpDyRJ5BvEEqKR+zA3d27sN0KTEmZBsQpQYH+lEl1+M0l5Y3oVOo na6kXzfpomIHjuXyRHDIhuuscqrybQBuB1gdsJCgI6mLW01zhlKxYMX5xnjz JVwC6XnS/gdHL+n3TSP4M46sar70fu01rSvMVY/IPRi+yBF38hlp49DDma7B rZHkgF7yVHoWnjM249SyKy/jgNb966f3bxhgZIDpV4jRHhnBQV0+oA== =VBlm -----END PGP SIGNATURE----- -----------------------56369eeff82fc88f89512ee2d078f35d--