page allocation failure on "zfs set snapdev=visible myPOOL/mydata1"

[muzyk10]

After zfs set snapdev=visible zfsPOOL/myzfsdata1 the kernel output this to dmesg:

[Tue Oct 21 10:39:51 2014] zfs: page allocation failure: order:4, mode:0x10c0d0 [Tue Oct 21 10:39:51 2014] Pid: 31834, comm: zfs Tainted: P O 3.8.13-gentoo #3 [Tue Oct 21 10:39:51 2014] Call Trace: [Tue Oct 21 10:39:51 2014] [] warn_alloc_failed+0xee/0x140 [Tue Oct 21 10:39:51 2014] [] ? alloc_pages_direct_compact+0x1a8/0x1ba [Tue Oct 21 10:39:51 2014] [] __alloc_pages_nodemask+0x733/0x960 [Tue Oct 21 10:39:51 2014] [] ? zprop_name_to_prop+0x34/0x50 [zcommon] [Tue Oct 21 10:39:51 2014] [] alloc_pages_current+0xb5/0x170 [Tue Oct 21 10:39:51 2014] [] get_free_pages+0x9/0x40 [Tue Oct 21 10:39:51 2014] [] kmalloc_order_trace+0x3a/0xc0 [Tue Oct 21 10:39:51 2014] [] check_partition+0x2b/0x200 [Tue Oct 21 10:39:51 2014] [] rescan_partitions+0xb3/0x2b0 [Tue Oct 21 10:39:51 2014] [] __blkdev_get+0x345/0x420 [Tue Oct 21 10:39:51 2014] [] blkdev_get+0x4e/0x300 [Tue Oct 21 10:39:51 2014] [] ? unlock_new_inode+0x42/0x70 [Tue Oct 21 10:39:51 2014] [] ? bdget+0x115/0x130 [Tue Oct 21 10:39:51 2014] [] add_disk+0x405/0x4a0 [Tue Oct 21 10:39:51 2014] [] ? kfree+0x3f/0x150 [Tue Oct 21 10:39:51 2014] [] zrl_is_locked+0x49b/0x1780 [zfs] [Tue Oct 21 10:39:51 2014] [] ? kmem_asprintf+0x48/0x60 [spl] [Tue Oct 21 10:39:51 2014] [] zvol_remove_minor+0xef/0x110 [zfs] [Tue Oct 21 10:39:51 2014] [] dmu_objset_userspace_present+0x2d/0x30 [zfs] [Tue Oct 21 10:39:51 2014] [] dmu_objset_find_spa+0x332/0x490 [zfs] [Tue Oct 21 10:39:51 2014] [] ? dmu_objset_userspace_present+0x20/0x30 [zfs] [Tue Oct 21 10:39:51 2014] [] dmu_objset_find+0x28/0x30 [zfs] [Tue Oct 21 10:39:51 2014] [] ? zvol_remove_minor+0x90/0x110 [zfs] [Tue Oct 21 10:39:51 2014] [] zvol_set_snapdev+0x21/0x30 [zfs] [Tue Oct 21 10:39:51 2014] [] zfs_secpolicy_fsacl+0x3bc/0x830 [zfs] [Tue Oct 21 10:39:51 2014] [] ? cleanup_module+0x1e/0x30 [zcommon] [Tue Oct 21 10:39:51 2014] [] ? zprop_index_to_string+0x2b/0xa0 [zcommon] [Tue Oct 21 10:39:51 2014] [] zfs_set_prop_nvlist+0x17a/0x1890 [zfs] [Tue Oct 21 10:39:51 2014] [] zfs_set_prop_nvlist+0x1586/0x1890 [zfs] [Tue Oct 21 10:39:51 2014] [] ? pool_status_check+0x61/0x260 [zfs] [Tue Oct 21 10:39:51 2014] [] pool_status_check+0x177/0x260 [zfs] [Tue Oct 21 10:39:51 2014] [] do_vfs_ioctl+0x8e/0x4e0 [Tue Oct 21 10:39:51 2014] [] ? file_has_perm+0x8f/0xa0 [Tue Oct 21 10:39:51 2014] [] sys_ioctl+0x91/0xb0 [Tue Oct 21 10:39:51 2014] [] system_call_fastpath+0x16/0x1b [Tue Oct 21 10:39:51 2014] Mem-Info: [Tue Oct 21 10:39:51 2014] Node 0 DMA per-cpu: [Tue Oct 21 10:39:51 2014] CPU 0: hi: 0, btch: 1 usd: 0 [Tue Oct 21 10:39:51 2014] CPU 1: hi: 0, btch: 1 usd: 0 [Tue Oct 21 10:39:51 2014] CPU 2: hi: 0, btch: 1 usd: 0 [Tue Oct 21 10:39:51 2014] CPU 3: hi: 0, btch: 1 usd: 0 [Tue Oct 21 10:39:51 2014] CPU 4: hi: 0, btch: 1 usd: 0 [Tue Oct 21 10:39:51 2014] CPU 5: hi: 0, btch: 1 usd: 0 [Tue Oct 21 10:39:51 2014] CPU 6: hi: 0, btch: 1 usd: 0 [Tue Oct 21 10:39:51 2014] CPU 7: hi: 0, btch: 1 usd: 0 [Tue Oct 21 10:39:51 2014] Node 0 DMA32 per-cpu: [Tue Oct 21 10:39:51 2014] CPU 0: hi: 186, btch: 31 usd: 0 [Tue Oct 21 10:39:51 2014] CPU 1: hi: 186, btch: 31 usd: 0 [Tue Oct 21 10:39:51 2014] CPU 2: hi: 186, btch: 31 usd: 0 [Tue Oct 21 10:39:51 2014] CPU 3: hi: 186, btch: 31 usd: 128 [Tue Oct 21 10:39:51 2014] CPU 4: hi: 186, btch: 31 usd: 0 [Tue Oct 21 10:39:51 2014] CPU 5: hi: 186, btch: 31 usd: 0 [Tue Oct 21 10:39:51 2014] CPU 6: hi: 186, btch: 31 usd: 0 [Tue Oct 21 10:39:51 2014] CPU 7: hi: 186, btch: 31 usd: 0 [Tue Oct 21 10:39:51 2014] Node 0 Normal per-cpu: [Tue Oct 21 10:39:51 2014] CPU 0: hi: 186, btch: 31 usd: 0 [Tue Oct 21 10:39:51 2014] CPU 1: hi: 186, btch: 31 usd: 0 [Tue Oct 21 10:39:51 2014] CPU 2: hi: 186, btch: 31 usd: 0 [Tue Oct 21 10:39:51 2014] CPU 3: hi: 186, btch: 31 usd: 169 [Tue Oct 21 10:39:51 2014] CPU 4: hi: 186, btch: 31 usd: 0 [Tue Oct 21 10:39:51 2014] CPU 5: hi: 186, btch: 31 usd: 0 [Tue Oct 21 10:39:51 2014] CPU 6: hi: 186, btch: 31 usd: 0 [Tue Oct 21 10:39:51 2014] CPU 7: hi: 186, btch: 31 usd: 0 [Tue Oct 21 10:39:51 2014] active_anon:2360126 inactive_anon:182555 isolated_anon:0 [Tue Oct 21 10:39:51 2014] Node 0 DMA free:15892kB min:12kB low:12kB high:16kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15652kB managed:15908kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:16kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes [Tue Oct 21 10:39:51 2014] lowmem_reserve[]: 0 1995 24171 24171 [Tue Oct 21 10:39:51 2014] Node 0 DMA32 free:681024kB min:1640kB low:2048kB high:2460kB active_anon:104880kB inactive_anon:35092kB active_file:125284kB inactive_file:74376kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:2043528kB managed:1993508kB mlocked:0kB dirty:28kB writeback:0kB mapped:948kB shmem:4kB slab_reclaimable:81720kB slab_unreclaimable:18408kB kernel_stack:800kB pagetables:1880kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no [Tue Oct 21 10:39:51 2014] lowmem_reserve[]: 0 0 22176 22176 [Tue Oct 21 10:39:51 2014] Node 0 Normal free:1711868kB min:18248kB low:22808kB high:27372kB active_anon:9335624kB inactive_anon:695128kB active_file:728224kB inactive_file:1303068kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:22708224kB managed:22673940kB mlocked:0kB dirty:620kB writeback:0kB mapped:17784kB shmem:816kB slab_reclaimable:146212kB slab_unreclaimable:159168kB kernel_stack:2816kB pagetables:30812kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no [Tue Oct 21 10:39:51 2014] lowmem_reserve[]: 0 0 0 0 [Tue Oct 21 10:39:51 2014] Node 0 DMA: 1_4kB (U) 0_8kB 1_16kB (U) 0_32kB 2_64kB (U) 1_128kB (U) 1_256kB (U) 0_512kB 1_1024kB (U) 1_2048kB (R) 3_4096kB (M) = 15892kB [Tue Oct 21 10:39:51 2014] Node 0 DMA32: 46909_4kB (UEM) 33526_8kB (UEM) 13510_16kB (UEM) 285_32kB (UEM) 2_64kB (U) 0_128kB 0_256kB 0_512kB 0_1024kB 0_2048kB 0_4096kB = 681252kB [Tue Oct 21 10:39:51 2014] Node 0 Normal: 211059_4kB (UEM) 108265_8kB (UEM) 60_16kB (U) 5_32kB (UMR) 1_64kB (R) 0_128kB 1_256kB (R) 1_512kB (R) 1_1024kB (R) 0_2048kB 0*4096kB = 1713332kB [Tue Oct 21 10:39:51 2014] 588032 total pagecache pages [Tue Oct 21 10:39:51 2014] 30089 pages in swap cache [Tue Oct 21 10:39:51 2014] Swap cache stats: add 844046, delete 813957, find 1646963/1699227 [Tue Oct 21 10:39:51 2014] Free swap = 16302704kB [Tue Oct 21 10:39:51 2014] Total swap = 16777212kB [Tue Oct 21 10:39:51 2014] 6291440 pages RAM [Tue Oct 21 10:39:51 2014] 119625 pages reserved [Tue Oct 21 10:39:51 2014] 2653156 pages shared [Tue Oct 21 10:39:51 2014] 4952249 pages non-shared [Tue Oct 21 10:39:51 2014] zd560: unknown partition table

On the end it says that partition zd560 has unknown partition table which is normal. Specs: system: Gentoo kernel ver: Linux king 3.8.13-gentoo #3 SMP Sat Jun 8 18:28:09 CEST 2013 x86_64 Intel(R) Xeon(R) CPU E5450 @ 3.00GHz GenuineIntel GNU/Linux zfs ver: 0.6.2-r3 (gentoo ebuild) RAM: 24GB I'm concerned a bit because it's a production machine :) I'v also noticed that free memory (free -m) dropped almost to 0. After switching snapdev to hidden free -m shows something above 2GB. Is it a bug or just "normal" behavior .. ?

lucas

[behlendorf]

This indicates the kernel had a problem finding a large chunk of contiguous free memory. This can happen when memory is highly fragmented. Many of the planned memory management improvements should make this sort of thing less likely.

[behlendorf]

Closing. Now that ABD has been merged to master memory will not be as fragmented making this kind of failure far less likely.

[muzyk10]

thank You