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

Unhandled kernel page request under heavy NFS traffic (from Xen guest) #3850

Closed
niekbergboer opened this issue Sep 27, 2015 · 3 comments
Closed
Milestone

Comments

@niekbergboer
Copy link

CPUs:           4 (8 threads), Xeon E3-1265Lv3.
Memory:         32GB
VM/Hypervisor:  Xen 4.5; ZFS server runs as Dom0 with 2 cores / 4 threads and 16 GB RAM.
ECC mem:        yes
Distribution:       Debian GNU/Linux Jessie / 8
Kernel version:     Linux batalix 4.1.2tmem-tmem #1 SMP Thu Jul 16 11:52:26 CEST 2015 x86_64 GNU/Linux
SPL/ZFS source:     ZFS 0.6.5.1-4 (Debian daily package)
SPL/ZFS version:    # dmesg | grep -E 'SPL:|ZFS:'
            [   21.657438] SPL: Loaded module v0.6.5-1
[   21.814250] ZFS: Loaded module v0.6.5.1-4, ZFS pool version 5000, ZFS filesystem version 5
[   26.436382] SPL: using hostid 0x007f0101
Short  description: Heavy NFSv4 traffic causes kernel noise.

Under heavy NFSv4 traffic (which is synchronous, and goes to a ZFS dataset on a zpool that has ZIL devices), the kernel complains about an unhandled kernel page request:

[ 6457.910367] BUG: unable to handle kernel paging request at ffff8800aa8fe008
[ 6457.911215] IP: [] uioskip+0x4c/0xb0 [zcommon]
[ 6457.911938] PGD 180e067 PUD 3ffb21067 PMD 3ff9cc067 PTE 0
[ 6457.912616] Oops: 0000 [#1] SMP
[ 6457.913015] Modules linked in: xt_physdev br_netfilter iptable_filter ip_tables x_tables xen_netback xen_blkback binfmt_misc nfnetlink_queue nfnetlink_log nfnetlink bluetooth rfkill xen_gntdev xen_evtchn xenfs xen_privcmd crc32c_generic tun nfsd auth_rpcgss oid_registry nfs_acl nfs lockd grace fscache sunrpc ib_iser rdma_cm iw_cm ib_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi 8021q garp mrp bridge stp llc zfs(PO) zunicode(PO) zcommon(PO) znvpair(PO) spl(O) zavl(PO) iTCO_wdt iTCO_vendor_support x86_pkg_temp_thermal intel_powerclamp intel_rapl iosf_mbi pcspkr psmouse serio_raw i2c_i801 lpc_ich mfd_core i915 drm_kms_helper joydev mei_me evdev drm mei tpm_tis tpm battery video shpchp button ie31200_edac processor edac_core nct6775 hwmon_vid jc42 coretemp loop
[ 6457.922292] ipmi_watchdog ipmi_poweroff ipmi_devintf ipmi_msghandler fuse parport_pc ppdev lp parport autofs4 algif_skcipher af_alg dm_mirror dm_region_hash dm_log btrfs ext4 crc16 jbd2 mbcache xts sha256_ssse3 sha256_generic dm_crypt dm_mod raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq raid0 raid1 md_mod hid_microsoft hid_generic sg sd_mod usbhid hid crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel aesni_intel aes_x86_64 ahci lrw gf128mul glue_helper libahci ablk_helper cryptd libata firewire_ohci xhci_pci xhci_hcd ehci_pci igb i2c_algo_bit ehci_hcd firewire_core crc_itu_t i2c_core e1000e dca ptp usbcore pps_core usb_common mpt2sas raid_class scsi_transport_sas scsi_mod thermal fan thermal_sys
[ 6457.930792] CPU: 0 PID: 7895 Comm: nfsd Tainted: P O 4.1.2tmem-tmem #1
[ 6457.931694] Hardware name: Supermicro X10SAE/X10SAE, BIOS 2.00 04/21/2014
[ 6457.932494] task: ffff880419094d20 ti: ffff88041c00c000 task.ti: ffff88041c00c000
[ 6457.933377] RIP: e030:[] [] uioskip+0x4c/0xb0 [zcommon]
[ 6457.934384] RSP: e02b:ffff88041c00f890 EFLAGS: 00010286
[ 6457.935008] RAX: 0000000000000000 RBX: ffff88042ab25880 RCX: 00000000ffffffc0
[ 6457.935849] RDX: ffff8800aa8fe010 RSI: 0000000000020000 RDI: ffff88041c00fa90
[ 6457.936689] RBP: ffff88041c00fa90 R08: 0000000000000000 R09: 0000000000020000
[ 6457.989964] R10: ffff8803b5d0c3c8 R11: 0000000000000000 R12: ffff880420989000
[ 6458.043270] R13: 0000000000000000 R14: 0000000000020000 R15: ffff8803c924ec10
[ 6458.096638] FS: 0000000000000000(0000) GS:ffff880434a00000(0000) knlGS:ffff880434a00000
[ 6458.150145] CS: e033 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 6458.203353] CR2: ffff8800aa8fe008 CR3: 000000041a875000 CR4: 0000000000042660
[ 6458.256826] Stack:
[ 6458.309870] ffffffffc0902541 0000000000008001 0000000000000000 0000000000000000
[ 6458.363459] 0000000000000000 0000000000000000 0000000000020000 0000000000020000
[ 6458.416430] ffff8803c924e9f8 0000000000020000 0000000000020000 ffff8803ac4a2ab0
[ 6458.469167] Call Trace:
[ 6458.521439] [] ? zfs_write+0x471/0xb70 [zfs]
[ 6458.574640] [] ? dbuf_rele_and_unlock+0x2b8/0x430 [zfs]
[ 6458.628241] [] ? zpl_write_common_iovec+0x85/0xf0 [zfs]
[ 6458.681758] [] ? zpl_iter_write+0x9f/0xd0 [zfs]
[ 6458.735178] [] ? __sb_start_write+0x45/0x100
[ 6458.788455] [] ? zpl_compat_ioctl+0x20/0x20 [zfs]
[ 6458.841593] [] ? do_readv_writev+0x1cf/0x2a0
[ 6458.894582] [] ? zpl_read+0xa0/0xa0 [zfs]
[ 6458.947449] [] ? nfsd_proc_getattr+0xb0/0xb0 [nfsd]
[ 6458.999918] [] ? nfsd_proc_getattr+0xb0/0xb0 [nfsd]
[ 6459.051581] [] ? kmem_cache_alloc+0x77/0x490
[ 6459.103072] [] ? nfsd_vfs_write.isra.17+0x9d/0x360 [nfsd]
[ 6459.154657] [] ? nfsd_write+0x89/0x110 [nfsd]
[ 6459.206524] [] ? nfsd4_write+0x19b/0x200 [nfsd]
[ 6459.258278] [] ? nfsd4_proc_compound+0x36f/0x6b0 [nfsd]
[ 6459.309940] [] ? nfsd_dispatch+0xb2/0x210 [nfsd]
[ 6459.361378] [] ? svc_process_common+0x3e9/0x640 [sunrpc]
[ 6459.413325] [] ? svc_process+0x103/0x190 [sunrpc]
[ 6459.465350] [] ? nfsd+0xef/0x160 [nfsd]
[ 6459.517219] [] ? nfsd_destroy+0x60/0x60 [nfsd]
[ 6459.569091] [] ? kthread+0xc1/0xe0
[ 6459.620967] [] ? kthread_create_on_node+0x180/0x180
[ 6459.672961] [] ? ret_from_fork+0x42/0x70
[ 6459.724836] [] ? kthread_create_on_node+0x180/0x180
[ 6459.776744] Code: 4e 4c 8b 42 08 4c 39 c0 72 2a 8b 4f 08 48 83 c2 10 83 e9 01 0f 1f 00 4c 29 c0 48 89 17 48 83 c2 10 89 4f 08 83 e9 01 48 89 47 30 <4c> 8b 42 f8 49 39 c0 76 e3 48 01 77 10 49 29 f1 4c 89 4f 28 c3
[ 6459.831885] RIP [] uioskip+0x4c/0xb0 [zcommon]
[ 6459.885545] RSP
[ 6459.938560] CR2: ffff8800aa8fe008
[ 6459.991289] [drm:intel_crtc_set_config [i915]] ERROR failed to restore config after modeset failure
[ 6460.416010] ---[ end trace f2ef59211d63eb81 ]---

(the drm:intel line seems to be a red herring that just happened around the same time).

The Xen PHV Dom0 guest reports:

[ 6066.656127] nfs: server batalix not responding, still trying
[ 6101.472129] nfs: server batalix not responding, still trying
[ 6101.472149] nfs: server batalix not responding, still trying
[ 6120.052092] INFO: task bitcoind:2138 blocked for more than 120 seconds.
[ 6120.052110] Not tainted 4.2.0tmem-tmem #1
[ 6120.052118] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 6120.052128] bitcoind D 0000000000000001 0 2138 1 0x00000000
[ 6120.052143] ffff8800b9e104c0 0000000000000086 ffff8800b805bda8 ffff8800b7d78040
[ 6120.052171] 0000000000000000 ffff8800b805c000 ffff8800bfd15380 7fffffffffffffff
[ 6120.052195] ffffffff81532510 ffff8800b805bd78 ffff8800b805be58 ffffffff81531ddf
[ 6120.052228] Call Trace:
[ 6120.052245] [] ? bit_wait+0x50/0x50
[ 6120.052258] [] ? schedule+0x2f/0x70
[ 6120.052275] [] ? schedule_timeout+0x17a/0x240
[ 6120.052294] [] ? xen_clocksource_get_cycles+0x15/0x20
[ 6120.052305] [] ? bit_wait+0x50/0x50
[ 6120.052313] [] ? io_schedule_timeout+0x9d/0x110
[ 6120.052325] [] ? _raw_write_unlock_irqrestore+0x12/0x20
[ 6120.052344] [] ? prepare_to_wait+0x53/0x80
[ 6120.052356] [] ? bit_wait_io+0x35/0x60
[ 6120.052373] [] ? __wait_on_bit+0x58/0x90
[ 6120.052391] [] ? find_get_pages_tag+0x10e/0x150
[ 6120.052404] [] ? wait_on_page_bit+0xb8/0xc0
[ 6120.052419] [] ? autoremove_wake_function+0x30/0x30
[ 6120.052435] [] ? filemap_fdatawait_range+0xc4/0x130
[ 6120.052451] [] ? filemap_write_and_wait_range+0x3f/0x60
[ 6120.052468] [] ? nfs4_file_fsync+0x79/0x130 [nfsv4]
[ 6120.052483] [] ? do_fsync+0x38/0x60
[ 6120.052493] [] ? SyS_fdatasync+0x13/0x20
[ 6120.052503] [] ? system_call_fast_compare_end+0x18/0x6b
[ 6120.052514] [] ? system_call_fast_compare_end+0xc/0x6b
[ 6240.052142] INFO: task bitcoind:2138 blocked for more than 120 seconds.
[ 6240.052163] Not tainted 4.2.0tmem-tmem #1
[ 6240.052173] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 6240.052189] bitcoind D 0000000000000001 0 2138 1 0x00000000
[ 6240.052206] ffff8800b9e104c0 0000000000000086 ffff8800b805bda8 ffff8800b7d78040
[ 6240.052225] 0000000000000000 ffff8800b805c000 ffff8800bfd15380 7fffffffffffffff
[ 6240.052244] ffffffff81532510 ffff8800b805bd78 ffff8800b805be58 ffffffff81531ddf
[ 6240.052270] Call Trace:
[ 6240.052284] [] ? bit_wait+0x50/0x50
[ 6240.052294] [] ? schedule+0x2f/0x70
[ 6240.052307] [] ? schedule_timeout+0x17a/0x240
[ 6240.052324] [] ? xen_clocksource_get_cycles+0x15/0x20
[ 6240.052335] [] ? bit_wait+0x50/0x50
[ 6240.052344] [] ? io_schedule_timeout+0x9d/0x110
[ 6240.052359] [] ? _raw_write_unlock_irqrestore+0x12/0x20
[ 6240.052372] [] ? prepare_to_wait+0x53/0x80
[ 6240.052383] [] ? bit_wait_io+0x35/0x60
[ 6240.052392] [] ? __wait_on_bit+0x58/0x90
[ 6240.052405] [] ? find_get_pages_tag+0x10e/0x150
[ 6240.052420] [] ? wait_on_page_bit+0xb8/0xc0
[ 6240.052431] [] ? autoremove_wake_function+0x30/0x30
[ 6240.052443] [] ? filemap_fdatawait_range+0xc4/0x130
[ 6240.052455] [] ? filemap_write_and_wait_range+0x3f/0x60
[ 6240.052472] [] ? nfs4_file_fsync+0x79/0x130 [nfsv4]
[ 6240.052488] [] ? do_fsync+0x38/0x60
[ 6240.052499] [] ? SyS_fdatasync+0x13/0x20
[ 6240.052509] [] ? system_call_fast_compare_end+0x18/0x6b
[ 6240.052520] [] ? system_call_fast_compare_end+0xc/0x6b
[ 6360.052092] INFO: task bitcoind:2138 blocked for more than 120 seconds.
[ 6360.052111] Not tainted 4.2.0tmem-tmem #1
[ 6360.052120] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 6360.052133] bitcoind D 0000000000000001 0 2138 1 0x00000000
[ 6360.052149] ffff8800b9e104c0 0000000000000086 ffff8800b805bda8 ffff8800b7d78040
[ 6360.052176] 0000000000000000 ffff8800b805c000 ffff8800bfd15380 7fffffffffffffff
[ 6360.052200] ffffffff81532510 ffff8800b805bd78 ffff8800b805be58 ffffffff81531ddf
[ 6360.052223] Call Trace:
[ 6360.052236] [] ? bit_wait+0x50/0x50
[ 6360.052250] [] ? schedule+0x2f/0x70
[ 6360.052259] [] ? schedule_timeout+0x17a/0x240
[ 6360.052279] [] ? xen_clocksource_get_cycles+0x15/0x20
[ 6360.052290] [] ? bit_wait+0x50/0x50
[ 6360.052299] [] ? io_schedule_timeout+0x9d/0x110
[ 6360.052315] [] ? _raw_write_unlock_irqrestore+0x12/0x20
[ 6360.052328] [] ? prepare_to_wait+0x53/0x80
[ 6360.052339] [] ? bit_wait_io+0x35/0x60
[ 6360.052353] [] ? __wait_on_bit+0x58/0x90
[ 6360.052365] [] ? find_get_pages_tag+0x10e/0x150
[ 6360.052380] [] ? wait_on_page_bit+0xb8/0xc0
[ 6360.052392] [] ? autoremove_wake_function+0x30/0x30
[ 6360.052407] [] ? filemap_fdatawait_range+0xc4/0x130
[ 6360.052420] [] ? filemap_write_and_wait_range+0x3f/0x60
[ 6360.052440] [] ? nfs4_file_fsync+0x79/0x130 [nfsv4]
[ 6360.052452] [] ? do_fsync+0x38/0x60
[ 6360.052466] [] ? SyS_fdatasync+0x13/0x20
[ 6360.052477] [] ? system_call_fast_compare_end+0x18/0x6b
[ 6360.052496] [] ? system_call_fast_compare_end+0xc/0x6b
[ 6480.052110] INFO: task bitcoind:2138 blocked for more than 120 seconds.
[ 6480.052129] Not tainted 4.2.0tmem-tmem #1
[ 6480.052138] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 6480.052151] bitcoind D 0000000000000001 0 2138 1 0x00000000
[ 6480.052166] ffff8800b9e104c0 0000000000000086 ffff8800b805bda8 ffff8800b7d78040
[ 6480.052185] 0000000000000000 ffff8800b805c000 ffff8800bfd15380 7fffffffffffffff
[ 6480.052210] ffffffff81532510 ffff8800b805bd78 ffff8800b805be58 ffffffff81531ddf
[ 6480.052231] Call Trace:
[ 6480.052244] [] ? bit_wait+0x50/0x50
[ 6480.052253] [] ? schedule+0x2f/0x70
[ 6480.052266] [] ? schedule_timeout+0x17a/0x240
[ 6480.052285] [] ? xen_clocksource_get_cycles+0x15/0x20
[ 6480.052296] [] ? bit_wait+0x50/0x50
[ 6480.052305] [] ? io_schedule_timeout+0x9d/0x110
[ 6480.052316] [] ? _raw_write_unlock_irqrestore+0x12/0x20
[ 6480.052335] [] ? prepare_to_wait+0x53/0x80
[ 6480.052346] [] ? bit_wait_io+0x35/0x60
[ 6480.052356] [] ? __wait_on_bit+0x58/0x90
[ 6480.052367] [] ? find_get_pages_tag+0x10e/0x150
[ 6480.052379] [] ? wait_on_page_bit+0xb8/0xc0
[ 6480.052397] [] ? autoremove_wake_function+0x30/0x30
[ 6480.052409] [] ? filemap_fdatawait_range+0xc4/0x130
[ 6480.052421] [] ? filemap_write_and_wait_range+0x3f/0x60
[ 6480.052437] [] ? nfs4_file_fsync+0x79/0x130 [nfsv4]
[ 6480.052456] [] ? do_fsync+0x38/0x60
[ 6480.052466] [] ? SyS_fdatasync+0x13/0x20
[ 6480.052477] [] ? system_call_fast_compare_end+0x18/0x6b
[ 6480.052493] [] ? system_call_fast_compare_end+0xc/0x6b
[ 6600.052144] INFO: task bitcoind:2138 blocked for more than 120 seconds.
[ 6600.052165] Not tainted 4.2.0tmem-tmem #1
[ 6600.052175] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 6600.052190] bitcoind D 0000000000000001 0 2138 1 0x00000000
[ 6600.052207] ffff8800b9e104c0 0000000000000086 ffff8800b805bda8 ffff8800b7d78040
[ 6600.052226] 0000000000000000 ffff8800b805c000 ffff8800bfd15380 7fffffffffffffff
[ 6600.052245] ffffffff81532510 ffff8800b805bd78 ffff8800b805be58 ffffffff81531ddf
[ 6600.052272] Call Trace:
[ 6600.052288] [] ? bit_wait+0x50/0x50
[ 6600.052299] [] ? schedule+0x2f/0x70
[ 6600.052315] [] ? schedule_timeout+0x17a/0x240
[ 6600.052330] [] ? xen_clocksource_get_cycles+0x15/0x20
[ 6600.052341] [] ? bit_wait+0x50/0x50
[ 6600.052350] [] ? io_schedule_timeout+0x9d/0x110
[ 6600.052361] [] ? _raw_write_unlock_irqrestore+0x12/0x20
[ 6600.052387] [] ? prepare_to_wait+0x53/0x80
[ 6600.052398] [] ? bit_wait_io+0x35/0x60
[ 6600.052407] [] ? __wait_on_bit+0x58/0x90
[ 6600.052419] [] ? find_get_pages_tag+0x10e/0x150
[ 6600.052433] [] ? wait_on_page_bit+0xb8/0xc0
[ 6600.052447] [] ? autoremove_wake_function+0x30/0x30
[ 6600.052459] [] ? filemap_fdatawait_range+0xc4/0x130
[ 6600.052471] [] ? filemap_write_and_wait_range+0x3f/0x60
[ 6600.052486] [] ? nfs4_file_fsync+0x79/0x130 [nfsv4]
[ 6600.052505] [] ? do_fsync+0x38/0x60
[ 6600.052515] [] ? SyS_fdatasync+0x13/0x20
[ 6600.052525] [] ? system_call_fast_compare_end+0x18/0x6b
[ 6600.052543] [] ? system_call_fast_compare_end+0xc/0x6b
[ 6720.052140] INFO: task bitcoind:2138 blocked for more than 120 seconds.
[ 6720.052161] Not tainted 4.2.0tmem-tmem #1
[ 6720.052170] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 6720.052186] bitcoind D 0000000000000001 0 2138 1 0x00000000
[ 6720.052202] ffff8800b9e104c0 0000000000000086 ffff8800b805bda8 ffff8800b7d78040
[ 6720.052222] 0000000000000000 ffff8800b805c000 ffff8800bfd15380 7fffffffffffffff
[ 6720.052240] ffffffff81532510 ffff8800b805bd78 ffff8800b805be58 ffffffff81531ddf
[ 6720.052259] Call Trace:
[ 6720.052271] [] ? bit_wait+0x50/0x50
[ 6720.052283] [] ? schedule+0x2f/0x70
[ 6720.052293] [] ? schedule_timeout+0x17a/0x240
[ 6720.052309] [] ? xen_clocksource_get_cycles+0x15/0x20
[ 6720.052321] [] ? bit_wait+0x50/0x50
[ 6720.052331] [] ? io_schedule_timeout+0x9d/0x110
[ 6720.052342] [] ? _raw_write_unlock_irqrestore+0x12/0x20
[ 6720.052355] [] ? prepare_to_wait+0x53/0x80
[ 6720.052366] [] ? bit_wait_io+0x35/0x60
[ 6720.052376] [] ? __wait_on_bit+0x58/0x90
[ 6720.052389] [] ? find_get_pages_tag+0x10e/0x150
[ 6720.052400] [] ? wait_on_page_bit+0xb8/0xc0
[ 6720.052411] [] ? autoremove_wake_function+0x30/0x30
[ 6720.052423] [] ? filemap_fdatawait_range+0xc4/0x130
[ 6720.052436] [] ? filemap_write_and_wait_range+0x3f/0x60
[ 6720.052454] [] ? nfs4_file_fsync+0x79/0x130 [nfsv4]
[ 6720.052467] [] ? do_fsync+0x38/0x60
[ 6720.052477] [] ? SyS_fdatasync+0x13/0x20
[ 6720.052487] [] ? system_call_fast_compare_end+0x18/0x6b
[ 6720.052499] [] ? system_call_fast_compare_end+0xc/0x6b
[ 6840.052141] INFO: task bitcoind:2138 blocked for more than 120 seconds.
[ 6840.052162] Not tainted 4.2.0tmem-tmem #1
[ 6840.052171] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 6840.052186] bitcoind D 0000000000000001 0 2138 1 0x00000000
[ 6840.052203] ffff8800b9e104c0 0000000000000086 ffff8800b805bda8 ffff8800b7d78040
[ 6840.052222] 0000000000000000 ffff8800b805c000 ffff8800bfd15380 7fffffffffffffff
[ 6840.052240] ffffffff81532510 ffff8800b805bd78 ffff8800b805be58 ffffffff81531ddf
[ 6840.052258] Call Trace:
[ 6840.052271] [] ? bit_wait+0x50/0x50
[ 6840.052282] [] ? schedule+0x2f/0x70
[ 6840.052293] [] ? schedule_timeout+0x17a/0x240
[ 6840.052309] [] ? xen_clocksource_get_cycles+0x15/0x20
[ 6840.052321] [] ? bit_wait+0x50/0x50
[ 6840.052331] [] ? io_schedule_timeout+0x9d/0x110
[ 6840.052342] [] ? _raw_write_unlock_irqrestore+0x12/0x20
[ 6840.052355] [] ? prepare_to_wait+0x53/0x80
[ 6840.052366] [] ? bit_wait_io+0x35/0x60
[ 6840.052377] [] ? __wait_on_bit+0x58/0x90
[ 6840.052390] [] ? find_get_pages_tag+0x10e/0x150
[ 6840.052401] [] ? wait_on_page_bit+0xb8/0xc0
[ 6840.052412] [] ? autoremove_wake_function+0x30/0x30
[ 6840.052424] [] ? filemap_fdatawait_range+0xc4/0x130
[ 6840.052436] [] ? filemap_write_and_wait_range+0x3f/0x60
[ 6840.052453] [] ? nfs4_file_fsync+0x79/0x130 [nfsv4]
[ 6840.052468] [] ? do_fsync+0x38/0x60
[ 6840.052479] [] ? SyS_fdatasync+0x13/0x20
[ 6840.052490] [] ? system_call_fast_compare_end+0x18/0x6b
[ 6840.052502] [] ? system_call_fast_compare_end+0xc/0x6b
[ 6960.052175] INFO: task bitcoind:2138 blocked for more than 120 seconds.
[ 6960.052195] Not tainted 4.2.0tmem-tmem #1
[ 6960.052204] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 6960.052218] bitcoind D 0000000000000001 0 2138 1 0x00000000
[ 6960.052234] ffff8800b9e104c0 0000000000000086 ffff8800b805bda8 ffff8800b7d78040
[ 6960.052253] 0000000000000000 ffff8800b805c000 ffff8800bfd15380 7fffffffffffffff
[ 6960.052271] ffffffff81532510 ffff8800b805bd78 ffff8800b805be58 ffffffff81531ddf
[ 6960.052298] Call Trace:
[ 6960.052311] [] ? bit_wait+0x50/0x50
[ 6960.052321] [] ? schedule+0x2f/0x70
[ 6960.052335] [] ? schedule_timeout+0x17a/0x240
[ 6960.052351] [] ? xen_clocksource_get_cycles+0x15/0x20
[ 6960.052362] [] ? bit_wait+0x50/0x50
[ 6960.052371] [] ? io_schedule_timeout+0x9d/0x110
[ 6960.052383] [] ? _raw_write_unlock_irqrestore+0x12/0x20
[ 6960.052399] [] ? prepare_to_wait+0x53/0x80
[ 6960.052410] [] ? bit_wait_io+0x35/0x60
[ 6960.052420] [] ? __wait_on_bit+0x58/0x90
[ 6960.052433] [] ? find_get_pages_tag+0x10e/0x150
[ 6960.052445] [] ? wait_on_page_bit+0xb8/0xc0
[ 6960.052459] [] ? autoremove_wake_function+0x30/0x30
[ 6960.052471] [] ? filemap_fdatawait_range+0xc4/0x130
[ 6960.052484] [] ? filemap_write_and_wait_range+0x3f/0x60
[ 6960.052501] [] ? nfs4_file_fsync+0x79/0x130 [nfsv4]
[ 6960.052518] [] ? do_fsync+0x38/0x60
[ 6960.052528] [] ? SyS_fdatasync+0x13/0x20
[ 6960.052538] [] ? system_call_fast_compare_end+0x18/0x6b
[ 6960.052553] [] ? system_call_fast_compare_end+0xc/0x6b
[ 7080.052141] INFO: task bitcoind:2138 blocked for more than 120 seconds.
[ 7080.052162] Not tainted 4.2.0tmem-tmem #1
[ 7080.052172] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 7080.052187] bitcoind D 0000000000000001 0 2138 1 0x00000000
[ 7080.052204] ffff8800b9e104c0 0000000000000086 ffff8800b805bda8 ffff8800b7d78040
[ 7080.052223] 0000000000000000 ffff8800b805c000 ffff8800bfd15380 7fffffffffffffff
[ 7080.052241] ffffffff81532510 ffff8800b805bd78 ffff8800b805be58 ffffffff81531ddf
[ 7080.052268] Call Trace:
[ 7080.052281] [] ? bit_wait+0x50/0x50
[ 7080.052291] [] ? schedule+0x2f/0x70
[ 7080.052305] [] ? schedule_timeout+0x17a/0x240
[ 7080.052322] [] ? xen_clocksource_get_cycles+0x15/0x20
[ 7080.052333] [] ? bit_wait+0x50/0x50
[ 7080.052342] [] ? io_schedule_timeout+0x9d/0x110
[ 7080.052357] [] ? _raw_write_unlock_irqrestore+0x12/0x20
[ 7080.052370] [] ? prepare_to_wait+0x53/0x80
[ 7080.052381] [] ? bit_wait_io+0x35/0x60
[ 7080.052394] [] ? __wait_on_bit+0x58/0x90
[ 7080.052407] [] ? find_get_pages_tag+0x10e/0x150
[ 7080.052419] [] ? wait_on_page_bit+0xb8/0xc0
[ 7080.052434] [] ? autoremove_wake_function+0x30/0x30
[ 7080.052445] [] ? filemap_fdatawait_range+0xc4/0x130
[ 7080.052461] [] ? filemap_write_and_wait_range+0x3f/0x60
[ 7080.052478] [] ? nfs4_file_fsync+0x79/0x130 [nfsv4]
[ 7080.052495] [] ? do_fsync+0x38/0x60
[ 7080.052505] [] ? SyS_fdatasync+0x13/0x20
[ 7080.052519] [] ? system_call_fast_compare_end+0x18/0x6b
[ 7080.052531] [] ? system_call_fast_compare_end+0xc/0x6b
[ 7200.052141] INFO: task bitcoind:2138 blocked for more than 120 seconds.
[ 7200.052163] Not tainted 4.2.0tmem-tmem #1
[ 7200.052172] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 7200.052187] bitcoind D 0000000000000001 0 2138 1 0x00000000
[ 7200.052203] ffff8800b9e104c0 0000000000000086 ffff8800b805bda8 ffff8800b7d78040
[ 7200.052222] 0000000000000000 ffff8800b805c000 ffff8800bfd15380 7fffffffffffffff
[ 7200.052240] ffffffff81532510 ffff8800b805bd78 ffff8800b805be58 ffffffff81531ddf
[ 7200.052259] Call Trace:
[ 7200.052279] [] ? bit_wait+0x50/0x50
[ 7200.052290] [] ? schedule+0x2f/0x70
[ 7200.052300] [] ? schedule_timeout+0x17a/0x240
[ 7200.052319] [] ? xen_clocksource_get_cycles+0x15/0x20
[ 7200.052331] [] ? bit_wait+0x50/0x50
[ 7200.052340] [] ? io_schedule_timeout+0x9d/0x110
[ 7200.052351] [] ? _raw_write_unlock_irqrestore+0x12/0x20
[ 7200.052365] [] ? prepare_to_wait+0x53/0x80
[ 7200.052379] [] ? bit_wait_io+0x35/0x60
[ 7200.052388] [] ? __wait_on_bit+0x58/0x90
[ 7200.052401] [] ? find_get_pages_tag+0x10e/0x150
[ 7200.052413] [] ? wait_on_page_bit+0xb8/0xc0
[ 7200.052424] [] ? autoremove_wake_function+0x30/0x30
[ 7200.052439] [] ? filemap_fdatawait_range+0xc4/0x130
[ 7200.052452] [] ? filemap_write_and_wait_range+0x3f/0x60
[ 7200.052469] [] ? nfs4_file_fsync+0x79/0x130 [nfsv4]
[ 7200.052486] [] ? do_fsync+0x38/0x60
[ 7200.052496] [] ? SyS_fdatasync+0x13/0x20
[ 7200.052510] [] ? system_call_fast_compare_end+0x18/0x6b
[ 7200.052521] [] ? system_call_fast_compare_end+0xc/0x6b

Note that the guest was started later than the host, so the times are unfortunately not comparable.

@kernelOfTruth
Copy link
Contributor

referencing #3806 zcommon: unable to handle kernel paging request at ffff880073eb6008

@behlendorf behlendorf added this to the 0.6.5.3 milestone Sep 28, 2015
@niekbergboer
Copy link
Author

I moved my guests from Xen to KVM, and the same thing happens; it does not appear to be Xen related.

@behlendorf
Copy link
Contributor

@niekbergboer the patch in #3853 should address this issue, you can cherry pick it if you need an immediate solution.

@behlendorf behlendorf modified the milestones: 0.6.5.2, 0.6.5.3 Sep 29, 2015
nedbass pushed a commit that referenced this issue Sep 30, 2015
When doing uioskip to skip an iovec to the very end, the current loop
condition will falsely check pass the end of iovec. We fix this checking
uio_iovcnt first.

Signed-off-by: Chunwei Chen <tuxoko@gmail.com>
Signed-off-by: Brian Behlendorf <behlendorf1@llnl.gov>
Closes #3806
Closes #3850
MorpheusTeam pushed a commit to Xyratex/lustre-stable that referenced this issue Oct 17, 2015
ZFS/SPL 0.6.5.2

Bug Fixes
* Init script fixes openzfs/zfs#3816
* Fix uioskip crash when skip to end openzfs/zfs#3806
  openzfs/zfs#3850
* Userspace can trigger an assertion openzfs/zfs#3792
* Fix quota userused underflow bug openzfs/zfs#3789
* Fix performance regression from unwanted synchronous I/O
  openzfs/zfs#3780
* Fix deadlock during ARC reclaim openzfs/zfs#3808
  openzfs/zfs#3834
* Fix deadlock with zfs receive and clamscan openzfs/zfs#3719
* Allow NFS activity to defer snapshot unmounts openzfs/zfs#3794
* Linux 4.3 compatibility openzfs/zfs#3799
* Zed reload fixes openzfs/zfs#3773
* Fix PAX Patch/Grsec SLAB_USERCOPY panic openzfs/zfs#3796
* Always remove during dkms uninstall/update openzfs/spl#476

ZFS/SPL 0.6.5.1

Bug Fixes

* Fix zvol corruption with TRIM/discard openzfs/zfs#3798
* Fix NULL as mount(2) syscall data parameter openzfs/zfs#3804
* Fix xattr=sa dataset property not honored openzfs/zfs#3787

ZFS/SPL 0.6.5

Supported Kernels

* Compatible with 2.6.32 - 4.2 Linux kernels.

New Functionality

* Support for temporary mount options.
* Support for accessing the .zfs/snapshot over NFS.
* Support for estimating send stream size when source is a bookmark.
* Administrative commands are allowed to use reserved space improving
  robustness.
* New notify ZEDLETs support email and pushbullet notifications.
* New keyword 'slot' for vdev_id.conf to control what is use for the
  slot number.
* New zpool export -a option unmounts and exports all imported pools.
* New zpool iostat -y omits the first report with statistics since
  boot.
* New zdb can now open the root dataset.
* New zdb can print the numbers of ganged blocks.
* New zdb -ddddd can print details of block pointer objects.
* New zdb -b performance improved.
* New zstreamdump -d prints contents of blocks.

New Feature Flags

* large_blocks - This feature allows the record size on a dataset to
be set larger than 128KB. We currently support block sizes from 512
bytes to 16MB. The benefits of larger blocks, and thus larger IO, need
to be weighed against the cost of COWing a giant block to modify one
byte. Additionally, very large blocks can have an impact on I/O
latency, and also potentially on the memory allocator. Therefore, we
do not allow the record size to be set larger than zfs_max_recordsize
(default 1MB). Larger blocks can be created by changing this tuning,
pools with larger blocks can always be imported and used, regardless
of this setting.

* filesystem_limits - This feature enables filesystem and snapshot
limits. These limits can be used to control how many filesystems
and/or snapshots can be created at the point in the tree on which the
limits are set.

*Performance*

* Improved zvol performance on all kernels (>50% higher throughput,
  >20% lower latency)
* Improved zil performance on Linux 2.6.39 and earlier kernels (10x
  lower latency)
* Improved allocation behavior on mostly full SSD/file pools (5% to
  10% improvement on 90% full pools)
* Improved performance when removing large files.
* Caching improvements (ARC):
** Better cached read performance due to reduced lock contention.
** Smarter heuristics for managing the total size of the cache and the
   distribution of data/metadata.
** Faster release of cached buffers due to unexpected memory pressure.

*Changes in Behavior*

* Default reserved space was increased from 1.6% to 3.3% of total pool
capacity. This default percentage can be controlled through the new
spa_slop_shift module option, setting it to 6 will restore the
previous percentage.

* Loading of the ZFS module stack is now handled by systemd or the
sysv init scripts. Invoking the zfs/zpool commands will not cause the
modules to be automatically loaded. The previous behavior can be
restored by setting the ZFS_MODULE_LOADING=yes environment variable
but this functionality will be removed in a future release.

* Unified SYSV and Gentoo OpenRC initialization scripts. The previous
functionality has been split in to zfs-import, zfs-mount, zfs-share,
and zfs-zed scripts. This allows for independent control of the
services and is consistent with the unit files provided for a systemd
based system. Complete details of the functionality provided by the
updated scripts can be found here.

* Task queues are now dynamic and worker threads will be created and
destroyed as needed. This allows the system to automatically tune
itself to ensure the optimal number of threads are used for the active
workload which can result in a performance improvement.

* Task queue thread priorities were correctly aligned with the default
Linux file system thread priorities. This allows ZFS to compete fairly
with other active Linux file systems when the system is under heavy
load.

* When compression=on the default compression algorithm will be lz4 as
long as the feature is enabled. Otherwise the default remains lzjb.
Similarly lz4 is now the preferred method for compressing meta data
when available.

* The use of mkdir/rmdir/mv in the .zfs/snapshot directory has been
disabled by default both locally and via NFS clients. The
zfs_admin_snapshot module option can be used to re-enable this
functionality.

* LBA weighting is automatically disabled on files and SSDs ensuring
the entire device is used fairly.
* iostat accounting on zvols running on kernels older than Linux 3.19
is no longer supported.

* The known issues preventing swap on zvols for Linux 3.9 and newer
kernels have been resolved. However, deadlocks are still possible for
older kernels.

Module Options

* Changed zfs_arc_c_min default from 4M to 32M to accommodate large
  blocks.
* Added metaslab_aliquot to control how many bytes are written to a
  top-level vdev before moving on to the next one. Increasing this may
  be helpful when using blocks larger than 1M.
* Added spa_slop_shift, see 'reserved space' comment in the 'changes
  to behavior' section.
* Added zfs_admin_snapshot, enable/disable the use of mkdir/rmdir/mv
  in .zfs/snapshot directory.
* Added zfs_arc_lotsfree_percent, throttle I/O when free system
  memory drops below this percentage.
* Added zfs_arc_num_sublists_per_state, used to allow more
  fine-grained locking.
* Added zfs_arc_p_min_shift, used to set a floor on arc_p.
* Added zfs_arc_sys_free, the target number of bytes the ARC should
  leave as free.
* Added zfs_dbgmsg_enable, used to enable the 'dbgmsg' kstat.
* Added zfs_dbgmsg_maxsize, sets the maximum size of the dbgmsg
  buffer.
* Added zfs_max_recordsize, used to control the maximum allowed
  record size.
* Added zfs_arc_meta_strategy, used to select the preferred ARC
  reclaim strategy.
* Removed metaslab_min_alloc_size, it was unused internally due to
  prior changes.
* Removed zfs_arc_memory_throttle_disable, replaced by
  zfs_arc_lotsfree_percent.
* Removed zvol_threads, zvols no longer require a dedicated task
  queue.
* See zfs-module-parameters(5) for complete details on available
  module options.

Bug Fixes

* Improved documentation with many updates, corrections, and
  additions.
* Improved sysv, systemd, initramfs, and dracut support.
* Improved block pointer validation before issuing IO.
* Improved scrub pause heuristics.
* Improved test coverage.
* Improved heuristics for automatic repair when zfs_recover=1 module
  option is set.
* Improved debugging infrastructure via 'dbgmsg' kstat.
* Improved zpool import performance.
* Fixed deadlocks in direct memory reclaim.
* Fixed deadlock on db_mtx and dn_holds.
* Fixed deadlock in dmu_objset_find_dp().
* Fixed deadlock during zfs rollback.
* Fixed kernel panic due to tsd_exit() in ZFS_EXIT.
* Fixed kernel panic when adding a duplicate dbuf to dn_dbufs.
* Fixed kernel panic due to security / ACL creation failure.
* Fixed kernel panic on unmount due to iput taskq.
* Fixed panic due to corrupt nvlist when running utilities.
* Fixed panic on unmount due to not waiting for all znodes to be
  released.
* Fixed panic with zfs clone from different source and target pools.
* Fixed NULL pointer dereference in dsl_prop_get_ds().
* Fixed NULL pointer dereference in dsl_prop_notify_all_cb().
* Fixed NULL pointer dereference in zfsdev_getminor().
* Fixed I/Os are now aggregated across ZIO priority classes.
* Fixed .zfs/snapshot auto-mounting for all supported kernels.
* Fixed 3-digit octal escapes by changing to 4-digit which
  disambiguate the output.
* Fixed hard lockup due to infinite loop in zfs_zget().
* Fixed misreported 'alloc' value for cache devices.
* Fixed spurious hung task watchdog stack traces.
* Fixed direct memory reclaim deadlocks.
* Fixed module loading in zfs import systemd service.
* Fixed intermittent libzfs_init() failure to open /dev/zfs.
* Fixed hot-disk sparing for disk vdevs
* Fixed system spinning during ARC reclaim.
* Fixed formatting errors in {{zfs(8)}}
* Fixed zio pipeline stall by having callers invoke next stage.
* Fixed assertion failed in zrl_tryenter().
* Fixed memory leak in make_root_vdev().
* Fixed memory leak in zpool_in_use().
* Fixed memory leak in libzfs when doing rollback.
* Fixed hold leak in dmu_recv_end_check().
* Fixed refcount leak in bpobj_iterate_impl().
* Fixed misuse of input argument in traverse_visitbp().
* Fixed missing missing mutex_destroy() calls.
* Fixed integer overflows in dmu_read/dmu_write.
* Fixed verify() failure in zio_done().
* Fixed zio_checksum_error() to only include info for ECKSUM errors.
* Fixed -ESTALE to force lookup on missing NFS file handles.
* Fixed spurious failures from dsl_dataset_hold_obj().
* Fixed zfs compressratio when using with 4k sector size.
* Fixed spurious watchdog warnings in prefetch thread.
* Fixed unfair disk space allocation when vdevs are of unequal size.
* Fixed ashift accounting error writing to cache devices.
* Fixed zdb -d has false positive warning when
  feature@large_blocks=disabled.
* Fixed zdb -h | -i seg fault.
* Fixed force-received full stream into a dataset if it has a
  snapshot.
* Fixed snapshot error handling.
* Fixed 'hangs' while deleting large files.
* Fixed lock contention (rrw_exit) while running a read only load.
* Fixed error message when creating a pool to include all problematic
  devices.
* Fixed Xen virtual block device detection, partitions are now
  created.
* Fixed missing E2BIG error handling in zfs_setprop_error().
* Fixed zpool import assertion in libzfs_import.c.
* Fixed zfs send -nv output to stderr.
* Fixed idle pool potentially running itself out of space.
* Fixed narrow race which allowed read(2) to access beyond fstat(2)'s
  reported end-of-file.
* Fixed support for VPATH builds.
* Fixed double counting of HDR_L2ONLY_SIZE in ARC.
* Fixed 'BUG: Bad page state' warning from kernel due to writeback
  flag.
* Fixed arc_available_memory() to check freemem.
* Fixed arc_memory_throttle() to check pageout.
* Fixed'zpool create warning when using zvols in debug builds.
* Fixed loop devices layered on ZFS with 4.1 kernels.
* Fixed zvol contribution to kernel entropy pool.
* Fixed handling of compression flags in arc header.
* Substantial changes to realign code base with illumos.
* Many additional bug fixes.

Signed-off-by: Nathaniel Clark <nathaniel.l.clark@intel.com>
Change-Id: I87c012aec9ec581b10a417d699dafc7d415abf63
Reviewed-on: http://review.whamcloud.com/16399
Tested-by: Jenkins
Reviewed-by: Alex Zhuravlev <alexey.zhuravlev@intel.com>
Tested-by: Maloo <hpdd-maloo@intel.com>
Reviewed-by: Andreas Dilger <andreas.dilger@intel.com>
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

3 participants