public inbox for linux-btrfs@vger.kernel.org
 help / color / mirror / Atom feed
From: Zygo Blaxell <ce3g8jdj@umail.furryterror.org>
To: linux-btrfs@vger.kernel.org
Subject: Re: WARNING at fs/btrfs/delayed-ref.c:296 btrfs_merge_delayed_refs+0x3dc/0x410 (new on 5.0.4, not in 5.0.3)
Date: Tue, 26 Mar 2019 00:30:07 -0400	[thread overview]
Message-ID: <20190326043005.GH16651@hungrycats.org> (raw)
In-Reply-To: <20190326025028.GG16651@hungrycats.org>

On Mon, Mar 25, 2019 at 10:50:28PM -0400, Zygo Blaxell wrote:
> Running balance, rsync, and dedupe, I get kernel warnings every few
> minutes on 5.0.4.  No warnings on 5.0.3 under similar conditions.
> 
> Mount options are:  flushoncommit,space_cache=v2,compress=zstd.
> 
> There are two different stacks on the warnings.  This one comes from
> btrfs balance:

[snip]

Possibly unrelated, but I'm also repeatably getting this in 5.0.4 and
not 5.0.3, after about 5 hours of uptime.  Different processes, same
kernel stack:

	[Mon Mar 25 23:35:17 2019] kworker/u8:4: page allocation failure: order:0, mode:0x404000(GFP_NOWAIT|__GFP_COMP), nodemask=(null),cpuset=/,mems_allowed=0
	[Mon Mar 25 23:35:17 2019] CPU: 2 PID: 29518 Comm: kworker/u8:4 Tainted: G        W         5.0.4-zb64-303ce93b05c9+ #1
	[Mon Mar 25 23:35:17 2019] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
	[Mon Mar 25 23:35:17 2019] Workqueue: btrfs-submit btrfs_submit_helper
	[Mon Mar 25 23:35:17 2019] Call Trace:
	[Mon Mar 25 23:35:17 2019]  dump_stack+0x7d/0xbb
	[Mon Mar 25 23:35:17 2019]  warn_alloc+0x108/0x190
	[Mon Mar 25 23:35:17 2019]  __alloc_pages_nodemask+0x12c4/0x13f0
	[Mon Mar 25 23:35:17 2019]  ? rcu_read_lock_sched_held+0x68/0x70
	[Mon Mar 25 23:35:17 2019]  ? __update_load_avg_se+0x208/0x280
	[Mon Mar 25 23:35:17 2019]  cache_grow_begin+0x79/0x730
	[Mon Mar 25 23:35:17 2019]  ? cache_grow_begin+0x79/0x730
	[Mon Mar 25 23:35:17 2019]  ? ____cache_alloc_node+0x165/0x1e0
	[Mon Mar 25 23:35:17 2019]  fallback_alloc+0x1e4/0x280
	[Mon Mar 25 23:35:17 2019]  kmem_cache_alloc+0x2e9/0x310
	[Mon Mar 25 23:35:17 2019]  btracker_queue+0x47/0x170 [dm_cache]
	[Mon Mar 25 23:35:17 2019]  __lookup+0x51a/0x600 [dm_cache_smq]
	[Mon Mar 25 23:35:17 2019]  ? smq_lookup+0x37/0x7b [dm_cache_smq]
	[Mon Mar 25 23:35:17 2019]  smq_lookup+0x5d/0x7b [dm_cache_smq]
	[Mon Mar 25 23:35:18 2019]  map_bio.part.40+0x14d/0x5d0 [dm_cache]
	[Mon Mar 25 23:35:18 2019]  ? bio_detain_shared+0xb3/0x120 [dm_cache]
	[Mon Mar 25 23:35:18 2019]  cache_map+0x120/0x170 [dm_cache]
	[Mon Mar 25 23:35:18 2019]  __map_bio+0x42/0x1f0 [dm_mod]
	[Mon Mar 25 23:35:18 2019]  __split_and_process_non_flush+0x152/0x1e0 [dm_mod]
	[Mon Mar 25 23:35:18 2019]  __split_and_process_bio+0xd4/0x400 [dm_mod]
	[Mon Mar 25 23:35:18 2019]  ? lock_acquire+0xbc/0x1c0
	[Mon Mar 25 23:35:18 2019]  ? dm_get_live_table+0x5/0xc0 [dm_mod]
	[Mon Mar 25 23:35:18 2019]  dm_make_request+0x4d/0x100 [dm_mod]
	[Mon Mar 25 23:35:18 2019]  generic_make_request+0x297/0x470
	[Mon Mar 25 23:35:18 2019]  ? kvm_sched_clock_read+0x14/0x30
	[Mon Mar 25 23:35:18 2019]  ? submit_bio+0x6c/0x140
	[Mon Mar 25 23:35:18 2019]  submit_bio+0x6c/0x140
	[Mon Mar 25 23:35:18 2019]  run_scheduled_bios+0x1e6/0x500
	[Mon Mar 25 23:35:18 2019]  ? normal_work_helper+0x95/0x530
	[Mon Mar 25 23:35:18 2019]  normal_work_helper+0x95/0x530
	[Mon Mar 25 23:35:18 2019]  process_one_work+0x223/0x5d0
	[Mon Mar 25 23:35:18 2019]  worker_thread+0x4f/0x3b0
	[Mon Mar 25 23:35:18 2019]  kthread+0x106/0x140
	[Mon Mar 25 23:35:18 2019]  ? process_one_work+0x5d0/0x5d0
	[Mon Mar 25 23:35:18 2019]  ? kthread_park+0x90/0x90
	[Mon Mar 25 23:35:18 2019]  ret_from_fork+0x3a/0x50
	[Mon Mar 25 23:35:18 2019] Mem-Info:
	[Mon Mar 25 23:35:18 2019] active_anon:195872 inactive_anon:15658 isolated_anon:0
				    active_file:629653 inactive_file:308914 isolated_file:0
				    unevictable:65536 dirty:14449 writeback:27580 unstable:0
				    slab_reclaimable:492522 slab_unreclaimable:94393
				    mapped:10915 shmem:18846 pagetables:2178 bounce:0
				    free:66082 free_pcp:1963 free_cma:24
	[Mon Mar 25 23:35:18 2019] Node 0 active_anon:783488kB inactive_anon:62632kB active_file:2516656kB inactive_file:1235604kB unevictable:262144kB isolated(anon):0kB isolated(file):0kB mapped:43660kB dirty:57796kB writeback:110320kB shmem:75384kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 137216kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
	[Mon Mar 25 23:35:18 2019] Node 0 DMA free:15844kB min:132kB low:164kB high:196kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15908kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
	[Mon Mar 25 23:35:18 2019] lowmem_reserve[]: 0 2939 7906 7906 7906
	[Mon Mar 25 23:35:18 2019] Node 0 DMA32 free:116632kB min:81336kB low:87592kB high:93848kB active_anon:330436kB inactive_anon:31840kB active_file:531512kB inactive_file:491372kB unevictable:108544kB writepending:121984kB present:3129176kB managed:3019336kB mlocked:108544kB kernel_stack:2704kB pagetables:2944kB bounce:0kB free_pcp:3800kB local_pcp:256kB free_cma:0kB
	[Mon Mar 25 23:35:18 2019] lowmem_reserve[]: 0 0 4966 4966 4966
	[Mon Mar 25 23:35:18 2019] Node 0 Normal free:141932kB min:42420kB low:53024kB high:63628kB active_anon:453224kB inactive_anon:30792kB active_file:1984568kB inactive_file:737244kB unevictable:153600kB writepending:46544kB present:5242880kB managed:5102032kB mlocked:153600kB kernel_stack:7020kB pagetables:5768kB bounce:0kB free_pcp:4188kB local_pcp:1700kB free_cma:96kB
	[Mon Mar 25 23:35:18 2019] lowmem_reserve[]: 0 0 0 0 0
	[Mon Mar 25 23:35:18 2019] Node 0 DMA: 1*4kB (U) 0*8kB 0*16kB 1*32kB (U) 1*64kB (U) 1*128kB (U) 1*256kB (U) 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15844kB
	[Mon Mar 25 23:35:18 2019] Node 0 DMA32: 12698*4kB (UME) 6110*8kB (UME) 1087*16kB (UME) 4*32kB (M) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 117192kB
	[Mon Mar 25 23:35:18 2019] Node 0 Normal: 13507*4kB (UMEHC) 8008*8kB (UMEHC) 1374*16kB (UMEH) 3*32kB (H) 4*64kB (H) 4*128kB (H) 2*256kB (H) 1*512kB (H) 0*1024kB 0*2048kB 0*4096kB = 141964kB
	[Mon Mar 25 23:35:18 2019] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
	[Mon Mar 25 23:35:18 2019] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
	[Mon Mar 25 23:35:18 2019] 955001 total pagecache pages
	[Mon Mar 25 23:35:18 2019] 0 pages in swap cache
	[Mon Mar 25 23:35:18 2019] Swap cache stats: add 0, delete 0, find 0/0
	[Mon Mar 25 23:35:18 2019] Free swap  = 0kB
	[Mon Mar 25 23:35:18 2019] Total swap = 0kB
	[Mon Mar 25 23:35:18 2019] 2097012 pages RAM
	[Mon Mar 25 23:35:18 2019] 0 pages HighMem/MovableOnly
	[Mon Mar 25 23:35:18 2019] 62693 pages reserved
	[Mon Mar 25 23:35:18 2019] 4096 pages cma reserved
	[Mon Mar 25 23:35:18 2019] 0 pages hwpoisoned

As far as I can tell from logs of memory usage (recording memcg and
MemAvail stats every second), there are gigabytes of available (clean
page cache) RAM at all times during these tests.

  reply	other threads:[~2019-03-26  4:30 UTC|newest]

Thread overview: 10+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2019-03-26  2:50 WARNING at fs/btrfs/delayed-ref.c:296 btrfs_merge_delayed_refs+0x3dc/0x410 (new on 5.0.4, not in 5.0.3) Zygo Blaxell
2019-03-26  4:30 ` Zygo Blaxell [this message]
2019-03-26  8:42   ` Nikolay Borisov
2019-03-26 15:09     ` Zygo Blaxell
2019-03-26 15:13       ` Nikolay Borisov
2019-03-26 15:45         ` Zygo Blaxell
2019-03-26 15:30   ` BUG: workqueue lockup - pool cpus=0-3 flags=0x4 nice=0 stuck for 20915s! (on 4.20+) Zygo Blaxell
2019-05-15 20:27   ` btrfs + KASAN + SLAB + lvmcache + rsync + kernel 5.0 = page allocation failure and/or OOM kills (solved...ish) Zygo Blaxell
2019-04-29 22:34 ` WARNING at fs/btrfs/delayed-ref.c:296 btrfs_merge_delayed_refs+0x3dc/0x410 (still on 5.0.10) Zygo Blaxell
2020-02-04  3:16   ` WARNING at fs/btrfs/delayed-ref.c:296 btrfs_merge_delayed_refs+0x3dc/0x410 (fixed in 5.2) Zygo Blaxell

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20190326043005.GH16651@hungrycats.org \
    --to=ce3g8jdj@umail.furryterror.org \
    --cc=linux-btrfs@vger.kernel.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox