Bug while moving files in pool via AFP #506

uclageek · 2011-12-26T09:12:36Z

Dec 26 00:17:40 Soundwave kernel: [22586.159999] BUG: soft lockup - CPU#0 stuck for 61s! [z_null_iss/0:5651]
Dec 26 00:17:40 Soundwave kernel: [22586.160004] Modules linked in: nls_utf8 hfsplus pci_stub vboxpci vboxnetadp vboxnetflt vboxdrv iptable_filter ip_tables x_tables binfmt_misc ppdev snd_hda_codec_atihdmi fbcon tileblit font bitblit softcursor vga16fb vgastate snd_hda_codec_via snd_seq_dummy snd_seq_oss snd_seq_midi snd_hda_intel snd_rawmidi snd_hda_codec snd_hwdep radeon snd_seq_midi_event snd_pcm_oss snd_seq ttm snd_mixer_oss drm_kms_helper snd_pcm snd_seq_device dell_wmi drm i2c_algo_bit snd_timer dcdbas snd psmouse serio_raw edac_core edac_mce_amd i2c_piix4 soundcore snd_page_alloc shpchp lp parport zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl zlib_deflate usbhid hid usb_storage pata_atiixp ahci r8169 mii
Dec 26 00:17:40 Soundwave kernel: [22586.160004] CPU 0:
Dec 26 00:17:40 Soundwave kernel: [22586.160004] Modules linked in: nls_utf8 hfsplus pci_stub vboxpci vboxnetadp vboxnetflt vboxdrv iptable_filter ip_tables x_tables binfmt_misc ppdev snd_hda_codec_atihdmi fbcon tileblit font bitblit softcursor vga16fb vgastate snd_hda_codec_via snd_seq_dummy snd_seq_oss snd_seq_midi snd_hda_intel snd_rawmidi snd_hda_codec snd_hwdep radeon snd_seq_midi_event snd_pcm_oss snd_seq ttm snd_mixer_oss drm_kms_helper snd_pcm snd_seq_device dell_wmi drm i2c_algo_bit snd_timer dcdbas snd psmouse serio_raw edac_core edac_mce_amd i2c_piix4 soundcore snd_page_alloc shpchp lp parport zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl zlib_deflate usbhid hid usb_storage pata_atiixp ahci r8169 mii
Dec 26 00:17:40 Soundwave kernel: [22586.160004] Pid: 5651, comm: z_null_iss/0 Tainted: P 2.6.32-37-server #81-Ubuntu Inspiron 546S
Dec 26 00:17:40 Soundwave kernel: [22586.160004] RIP: 0010:[] [] __ticket_spin_lock+0x19/0x20
Dec 26 00:17:40 Soundwave kernel: [22586.160004] RSP: 0018:ffff8801eca1fd60 EFLAGS: 00000202
Dec 26 00:17:40 Soundwave kernel: [22586.160004] RAX: 0000000000000000 RBX: ffff8801eca1fd60 RCX: ffff8801201d8b68
Dec 26 00:17:40 Soundwave kernel: [22586.160004] RDX: 0000000000000002 RSI: 0000000000000282 RDI: ffff8801201d8b2c
Dec 26 00:17:40 Soundwave kernel: [22586.160004] RBP: ffffffff81013c6e R08: ffff880217502e00 R09: 0000000000000001
Dec 26 00:17:40 Soundwave kernel: [22586.160004] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
Dec 26 00:17:40 Soundwave kernel: [22586.160004] R13: 0000000000000000 R14: ffff8801eca1fd50 R15: ffffffff81013ace
Dec 26 00:17:40 Soundwave kernel: [22586.160004] FS: 00007f1a620a4700(0000) GS:ffff880008c00000(0000) knlGS:0000000000000000
Dec 26 00:17:40 Soundwave kernel: [22586.160004] CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
Dec 26 00:17:40 Soundwave kernel: [22586.160004] CR2: 000000000235b808 CR3: 000000011c0a5000 CR4: 00000000000006f0
Dec 26 00:17:40 Soundwave kernel: [22586.160004] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Dec 26 00:17:40 Soundwave kernel: [22586.160004] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Dec 26 00:17:40 Soundwave kernel: [22586.160004] Call Trace:
Dec 26 00:17:40 Soundwave kernel: [22586.160004] [] ? _spin_lock+0xe/0x20
Dec 26 00:17:40 Soundwave kernel: [22586.160004] [] ? __mutex_unlock_slowpath+0x25/0x60
Dec 26 00:17:40 Soundwave kernel: [22586.160004] [] ? mutex_unlock+0x1b/0x20
Dec 26 00:17:40 Soundwave kernel: [22586.160004] [] ? zio_done+0x4b5/0xc00 [zfs]
Dec 26 00:17:40 Soundwave kernel: [22586.160004] [] ? zio_execute+0x99/0xf0 [zfs]
Dec 26 00:17:40 Soundwave kernel: [22586.160004] [] ? taskq_thread+0x1f4/0x3b0 [spl]
Dec 26 00:17:40 Soundwave kernel: [22586.160004] [] ? default_wake_function+0x0/0x20
Dec 26 00:17:40 Soundwave kernel: [22586.160004] [] ? taskq_thread+0x0/0x3b0 [spl]
Dec 26 00:17:40 Soundwave kernel: [22586.160004] [] ? kthread+0x96/0xa0
Dec 26 00:17:40 Soundwave kernel: [22586.160004] [] ? child_rip+0xa/0x20
Dec 26 00:17:40 Soundwave kernel: [22586.160004] [] ? kthread+0x0/0xa0
Dec 26 00:17:40 Soundwave kernel: [22586.160004] [] ? child_rip+0x0/0x20
Dec 26 00:18:46 Soundwave kernel: [22651.659998] BUG: soft lockup - CPU#0 stuck for 61s! [z_null_iss/0:5651]
Dec 26 00:18:46 Soundwave kernel: [22651.660004] Modules linked in: nls_utf8 hfsplus pci_stub vboxpci vboxnetadp vboxnetflt vboxdrv iptable_filter ip_tables x_tables binfmt_misc ppdev snd_hda_codec_atihdmi fbcon tileblit font bitblit softcursor vga16fb vgastate snd_hda_codec_via snd_seq_dummy snd_seq_oss snd_seq_midi snd_hda_intel snd_rawmidi snd_hda_codec snd_hwdep radeon snd_seq_midi_event snd_pcm_oss snd_seq ttm snd_mixer_oss drm_kms_helper snd_pcm snd_seq_device dell_wmi drm i2c_algo_bit snd_timer dcdbas snd psmouse serio_raw edac_core edac_mce_amd i2c_piix4 soundcore snd_page_alloc shpchp lp parport zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl zlib_deflate usbhid hid usb_storage pata_atiixp ahci r8169 mii
Dec 26 00:18:46 Soundwave kernel: [22651.660004] CPU 0:
Dec 26 00:18:46 Soundwave kernel: [22651.660004] Modules linked in: nls_utf8 hfsplus pci_stub vboxpci vboxnetadp vboxnetflt vboxdrv iptable_filter ip_tables x_tables binfmt_misc ppdev snd_hda_codec_atihdmi fbcon tileblit font bitblit softcursor vga16fb vgastate snd_hda_codec_via snd_seq_dummy snd_seq_oss snd_seq_midi snd_hda_intel snd_rawmidi snd_hda_codec snd_hwdep radeon snd_seq_midi_event snd_pcm_oss snd_seq ttm snd_mixer_oss drm_kms_helper snd_pcm snd_seq_device dell_wmi drm i2c_algo_bit snd_timer dcdbas snd psmouse serio_raw edac_core edac_mce_amd i2c_piix4 soundcore snd_page_alloc shpchp lp parport zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl zlib_deflate usbhid hid usb_storage pata_atiixp ahci r8169 mii
Dec 26 00:18:46 Soundwave kernel: [22651.660004] Pid: 5651, comm: z_null_iss/0 Tainted: P 2.6.32-37-server #81-Ubuntu Inspiron 546S
Dec 26 00:18:46 Soundwave kernel: [22651.660004] RIP: 0010:[] [] __ticket_spin_lock+0x19/0x20
Dec 26 00:18:46 Soundwave kernel: [22651.660004] RSP: 0018:ffff8801eca1fd60 EFLAGS: 00000202
Dec 26 00:18:46 Soundwave kernel: [22651.660004] RAX: 0000000000000000 RBX: ffff8801eca1fd60 RCX: ffff8801201d8b68
Dec 26 00:18:46 Soundwave kernel: [22651.660004] RDX: 0000000000000002 RSI: 0000000000000282 RDI: ffff8801201d8b2c
Dec 26 00:18:46 Soundwave kernel: [22651.660004] RBP: ffffffff81013c6e R08: ffff880217502e00 R09: 0000000000000001
Dec 26 00:18:46 Soundwave kernel: [22651.660004] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
Dec 26 00:18:46 Soundwave kernel: [22651.660004] R13: 0000000000000000 R14: ffff8801eca1fd50 R15: ffffffff81013ace
Dec 26 00:18:46 Soundwave kernel: [22651.660004] FS: 00007f1a620a4700(0000) GS:ffff880008c00000(0000) knlGS:0000000000000000
Dec 26 00:18:46 Soundwave kernel: [22651.660004] CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
Dec 26 00:18:46 Soundwave kernel: [22651.660004] CR2: 000000000235b808 CR3: 000000011c0a5000 CR4: 00000000000006f0
Dec 26 00:18:46 Soundwave kernel: [22651.660004] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Dec 26 00:18:46 Soundwave kernel: [22651.660004] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Dec 26 00:18:46 Soundwave kernel: [22651.660004] Call Trace:
Dec 26 00:18:46 Soundwave kernel: [22651.660004] [] ? _spin_lock+0xe/0x20
Dec 26 00:18:46 Soundwave kernel: [22651.660004] [] ? __mutex_unlock_slowpath+0x25/0x60
Dec 26 00:18:46 Soundwave kernel: [22651.660004] [] ? mutex_unlock+0x1b/0x20
Dec 26 00:18:46 Soundwave kernel: [22651.660004] [] ? zio_done+0x4b5/0xc00 [zfs]
Dec 26 00:18:46 Soundwave kernel: [22651.660004] [] ? zio_execute+0x99/0xf0 [zfs]
Dec 26 00:18:46 Soundwave kernel: [22651.660004] [] ? taskq_thread+0x1f4/0x3b0 [spl]
Dec 26 00:18:46 Soundwave kernel: [22651.660004] [] ? default_wake_function+0x0/0x20
Dec 26 00:18:46 Soundwave kernel: [22651.660004] [] ? taskq_thread+0x0/0x3b0 [spl]
Dec 26 00:18:46 Soundwave kernel: [22651.660004] [] ? kthread+0x96/0xa0
Dec 26 00:18:46 Soundwave kernel: [22651.660004] [] ? child_rip+0xa/0x20
Dec 26 00:18:46 Soundwave kernel: [22651.660004] [] ? kthread+0x0/0xa0
Dec 26 00:18:46 Soundwave kernel: [22651.660004] [] ? child_rip+0x0/0x20
Dec 26 00:19:15 Soundwave kernel: [22680.742553] INFO: task deluged:2933 blocked for more than 120 seconds.
Dec 26 00:19:15 Soundwave kernel: [22680.742560] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 26 00:19:15 Soundwave kernel: [22680.742566] deluged D 00000000ffffffff 0 2933 1 0x00000000
Dec 26 00:19:15 Soundwave kernel: [22680.742576] ffff8801fdef7a78 0000000000000082 0000000000015f00 0000000000015f00
Dec 26 00:19:15 Soundwave kernel: [22680.742584] ffff8801fddb83d0 ffff8801fdef7fd8 0000000000015f00 ffff8801fddb8000
Dec 26 00:19:15 Soundwave kernel: [22680.742594] 0000000000015f00 ffff8801fdef7fd8 0000000000015f00 ffff8801fddb83d0
Dec 26 00:19:15 Soundwave kernel: [22680.742601] Call Trace:
Dec 26 00:19:15 Soundwave kernel: [22680.742643] [] cv_wait_common+0x78/0xe0 [spl]
Dec 26 00:19:15 Soundwave kernel: [22680.742655] [] ? autoremove_wake_function+0x0/0x40
Dec 26 00:19:15 Soundwave kernel: [22680.742677] [] __cv_wait+0x13/0x20 [spl]
Dec 26 00:19:15 Soundwave kernel: [22680.742758] [] txg_wait_open+0x7b/0xa0 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.742814] [] dmu_tx_wait+0xed/0xf0 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.742886] [] zfs_write+0x3be/0xc90 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.742950] [] zpl_write_common+0x52/0x70 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.743011] [] zpl_write+0x68/0xa0 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.743073] [] ? zpl_write+0x0/0xa0 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.743082] [] do_loop_readv_writev+0x59/0x90
Dec 26 00:19:15 Soundwave kernel: [22680.743089] [] do_readv_writev+0x1de/0x1f0
Dec 26 00:19:15 Soundwave kernel: [22680.743098] [] ? futex_wake+0x112/0x130
Dec 26 00:19:15 Soundwave kernel: [22680.743104] [] ? do_futex+0xb8/0x1b0
Dec 26 00:19:15 Soundwave kernel: [22680.743111] [] vfs_writev+0x48/0x60
Dec 26 00:19:15 Soundwave kernel: [22680.743119] [] sys_writev+0x51/0xb0
Dec 26 00:19:15 Soundwave kernel: [22680.743129] [] system_call_fastpath+0x16/0x1b
Dec 26 00:19:15 Soundwave kernel: [22680.743157] INFO: task txg_sync:5813 blocked for more than 120 seconds.
Dec 26 00:19:15 Soundwave kernel: [22680.743161] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 26 00:19:15 Soundwave kernel: [22680.743165] txg_sync D 00000000ffffffff 0 5813 2 0x00000000
Dec 26 00:19:15 Soundwave kernel: [22680.743175] ffff8801e8dedb30 0000000000000046 0000000000015f00 0000000000015f00
Dec 26 00:19:15 Soundwave kernel: [22680.743182] ffff8801ec4f48d0 ffff8801e8dedfd8 0000000000015f00 ffff8801ec4f4500
Dec 26 00:19:15 Soundwave kernel: [22680.743188] 0000000000015f00 ffff8801e8dedfd8 0000000000015f00 ffff8801ec4f48d0
Dec 26 00:19:15 Soundwave kernel: [22680.743194] Call Trace:
Dec 26 00:19:15 Soundwave kernel: [22680.743204] [] __mutex_lock_slowpath+0x107/0x190
Dec 26 00:19:15 Soundwave kernel: [22680.743211] [] mutex_lock+0x23/0x50
Dec 26 00:19:15 Soundwave kernel: [22680.743229] [] cv_wait_common+0x80/0xe0 [spl]
Dec 26 00:19:15 Soundwave kernel: [22680.743236] [] ? autoremove_wake_function+0x0/0x40
Dec 26 00:19:15 Soundwave kernel: [22680.743253] [] __cv_wait+0x13/0x20 [spl]
Dec 26 00:19:15 Soundwave kernel: [22680.743321] [] zio_wait+0xeb/0x160 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.743386] [] vdev_label_sync_list+0x15f/0x170 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.743451] [] vdev_config_sync+0x11f/0x160 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.743512] [] spa_sync+0x726/0x9a0 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.743520] [] ? autoremove_wake_function+0x16/0x40
Dec 26 00:19:15 Soundwave kernel: [22680.743529] [] ? __wake_up+0x53/0x70
Dec 26 00:19:15 Soundwave kernel: [22680.743592] [] txg_sync_thread+0x225/0x3b0 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.743654] [] ? txg_sync_thread+0x0/0x3b0 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.743671] [] thread_generic_wrapper+0x68/0x80 [spl]
Dec 26 00:19:15 Soundwave kernel: [22680.743687] [] ? thread_generic_wrapper+0x0/0x80 [spl]
Dec 26 00:19:15 Soundwave kernel: [22680.743694] [] kthread+0x96/0xa0
Dec 26 00:19:15 Soundwave kernel: [22680.743702] [] child_rip+0xa/0x20
Dec 26 00:19:15 Soundwave kernel: [22680.743708] [] ? kthread+0x0/0xa0
Dec 26 00:19:15 Soundwave kernel: [22680.743712] [] ? child_rip+0x0/0x20
Dec 26 00:19:15 Soundwave kernel: [22680.743719] INFO: task afpd:17096 blocked for more than 120 seconds.
Dec 26 00:19:15 Soundwave kernel: [22680.743723] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 26 00:19:15 Soundwave kernel: [22680.743727] afpd D 00000000ffffffff 0 17096 15761 0x00000004
Dec 26 00:19:15 Soundwave kernel: [22680.743733] ffff8801a0dddb78 0000000000000082 0000000000015f00 0000000000015f00
Dec 26 00:19:15 Soundwave kernel: [22680.743739] ffff8801e77b5fd0 ffff8801a0dddfd8 0000000000015f00 ffff8801e77b5c00
Dec 26 00:19:15 Soundwave kernel: [22680.743745] 0000000000015f00 ffff8801a0dddfd8 0000000000015f00 ffff8801e77b5fd0
Dec 26 00:19:15 Soundwave kernel: [22680.743752] Call Trace:
Dec 26 00:19:15 Soundwave kernel: [22680.743769] [] cv_wait_common+0x78/0xe0 [spl]
Dec 26 00:19:15 Soundwave kernel: [22680.743776] [] ? autoremove_wake_function+0x0/0x40
Dec 26 00:19:15 Soundwave kernel: [22680.743795] [] __cv_wait+0x13/0x20 [spl]
Dec 26 00:19:15 Soundwave kernel: [22680.743856] [] txg_wait_open+0x7b/0xa0 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.743908] [] dmu_tx_wait+0xed/0xf0 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.743971] [] zfs_write+0x3be/0xc90 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.744035] [] zpl_write_common+0x52/0x70 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.744096] [] zpl_write+0x68/0xa0 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.744106] [] ? security_file_permission+0x16/0x20
Dec 26 00:19:15 Soundwave kernel: [22680.744112] [] vfs_write+0xb8/0x1a0
Dec 26 00:19:15 Soundwave kernel: [22680.744119] [] sys_pwrite64+0x82/0xa0
Dec 26 00:19:15 Soundwave kernel: [22680.744126] [] system_call_fastpath+0x16/0x1b
Dec 26 00:19:15 Soundwave kernel: [22680.744138] INFO: task zpool:21430 blocked for more than 120 seconds.
Dec 26 00:19:15 Soundwave kernel: [22680.744142] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 26 00:19:15 Soundwave kernel: [22680.744145] zpool D 0000000000000000 0 21430 21027 0x00000000
Dec 26 00:19:15 Soundwave kernel: [22680.744152] ffff880132b5fc28 0000000000000086 0000000000015f00 0000000000015f00
Dec 26 00:19:15 Soundwave kernel: [22680.744158] ffff88020442c8d0 ffff880132b5ffd8 0000000000015f00 ffff88020442c500
Dec 26 00:19:15 Soundwave kernel: [22680.744166] 0000000000015f00 ffff880132b5ffd8 0000000000015f00 ffff88020442c8d0
Dec 26 00:19:15 Soundwave kernel: [22680.744172] Call Trace:
Dec 26 00:19:15 Soundwave kernel: [22680.744192] [] __taskq_create+0x2b5/0x3a0 [spl]
Dec 26 00:19:15 Soundwave kernel: [22680.744199] [] ? autoremove_wake_function+0x0/0x40
Dec 26 00:19:15 Soundwave kernel: [22680.744263] [] spa_activate+0x251/0x300 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.744330] [] spa_open_common+0x11d/0x380 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.744394] [] spa_get_stats+0x49/0x270 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.744401] [] ? __kmalloc+0x14e/0x1a0
Dec 26 00:19:15 Soundwave kernel: [22680.744463] [] zfs_ioc_pool_stats+0x31/0x70 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.744527] [] zfsdev_ioctl+0xfd/0x1c0 [zfs]
Dec 26 00:19:15 Soundwave kernel: [22680.744534] [] vfs_ioctl+0x22/0xa0
Dec 26 00:19:15 Soundwave kernel: [22680.744540] [] do_vfs_ioctl+0x81/0x410
Dec 26 00:19:15 Soundwave kernel: [22680.744549] [] ? hrtimer_start_range_ns+0x14/0x20
Dec 26 00:19:15 Soundwave kernel: [22680.744555] [] sys_ioctl+0x81/0xa0
Dec 26 00:19:15 Soundwave kernel: [22680.744563] [] ? do_device_not_available+0xe/0x10
Dec 26 00:19:15 Soundwave kernel: [22680.744569] [] system_call_fastpath+0x16/0x1b
Dec 26 00:19:51 Soundwave kernel: [22717.159998] BUG: soft lockup - CPU#0 stuck for 61s! [z_null_iss/0:5651]
Dec 26 00:19:51 Soundwave kernel: [22717.160004] Modules linked in: nls_utf8 hfsplus pci_stub vboxpci vboxnetadp vboxnetflt vboxdrv iptable_filter ip_tables x_tables binfmt_misc ppdev snd_hda_codec_atihdmi fbcon tileblit font bitblit softcursor vga16fb vgastate snd_hda_codec_via snd_seq_dummy snd_seq_oss snd_seq_midi snd_hda_intel snd_rawmidi snd_hda_codec snd_hwdep radeon snd_seq_midi_event snd_pcm_oss snd_seq ttm snd_mixer_oss drm_kms_helper snd_pcm snd_seq_device dell_wmi drm i2c_algo_bit snd_timer dcdbas snd psmouse serio_raw edac_core edac_mce_amd i2c_piix4 soundcore snd_page_alloc shpchp lp parport zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl zlib_deflate usbhid hid usb_storage pata_atiixp ahci r8169 mii
Dec 26 00:19:51 Soundwave kernel: [22717.160004] CPU 0:
Dec 26 00:19:51 Soundwave kernel: [22717.160004] Modules linked in: nls_utf8 hfsplus pci_stub vboxpci vboxnetadp vboxnetflt vboxdrv iptable_filter ip_tables x_tables binfmt_misc ppdev snd_hda_codec_atihdmi fbcon tileblit font bitblit softcursor vga16fb vgastate snd_hda_codec_via snd_seq_dummy snd_seq_oss snd_seq_midi snd_hda_intel snd_rawmidi snd_hda_codec snd_hwdep radeon snd_seq_midi_event snd_pcm_oss snd_seq ttm snd_mixer_oss drm_kms_helper snd_pcm snd_seq_device dell_wmi drm i2c_algo_bit snd_timer dcdbas snd psmouse serio_raw edac_core edac_mce_amd i2c_piix4 soundcore snd_page_alloc shpchp lp parport zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl zlib_deflate usbhid hid usb_storage pata_atiixp ahci r8169 mii
Dec 26 00:19:51 Soundwave kernel: [22717.160004] Pid: 5651, comm: z_null_iss/0 Tainted: P 2.6.32-37-server #81-Ubuntu Inspiron 546S
Dec 26 00:19:51 Soundwave kernel: [22717.160004] RIP: 0010:[] [] __ticket_spin_lock+0x17/0x20
Dec 26 00:19:51 Soundwave kernel: [22717.160004] RSP: 0018:ffff8801eca1fd60 EFLAGS: 00000202
Dec 26 00:19:51 Soundwave kernel: [22717.160004] RAX: 0000000000000000 RBX: ffff8801eca1fd60 RCX: ffff8801201d8b68
Dec 26 00:19:51 Soundwave kernel: [22717.160004] RDX: 0000000000000002 RSI: 0000000000000282 RDI: ffff8801201d8b2c
Dec 26 00:19:51 Soundwave kernel: [22717.160004] RBP: ffffffff81013c6e R08: ffff880217502e00 R09: 0000000000000001
Dec 26 00:19:51 Soundwave kernel: [22717.160004] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
Dec 26 00:19:51 Soundwave kernel: [22717.160004] R13: 0000000000000000 R14: ffff8801eca1fd50 R15: ffffffff81013ace
Dec 26 00:19:51 Soundwave kernel: [22717.160004] FS: 00007f1a620a4700(0000) GS:ffff880008c00000(0000) knlGS:0000000000000000
Dec 26 00:19:51 Soundwave kernel: [22717.160004] CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
Dec 26 00:19:51 Soundwave kernel: [22717.160004] CR2: 000000000235b808 CR3: 000000011c0a5000 CR4: 00000000000006f0
Dec 26 00:19:51 Soundwave kernel: [22717.160004] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Dec 26 00:19:51 Soundwave kernel: [22717.160004] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Dec 26 00:19:51 Soundwave kernel: [22717.160004] Call Trace:
Dec 26 00:19:51 Soundwave kernel: [22717.160004] [] ? _spin_lock+0xe/0x20
Dec 26 00:19:51 Soundwave kernel: [22717.160004] [] ? __mutex_unlock_slowpath+0x25/0x60
Dec 26 00:19:51 Soundwave kernel: [22717.160004] [] ? mutex_unlock+0x1b/0x20
Dec 26 00:19:51 Soundwave kernel: [22717.160004] [] ? zio_done+0x4b5/0xc00 [zfs]
Dec 26 00:19:51 Soundwave kernel: [22717.160004] [] ? zio_execute+0x99/0xf0 [zfs]
Dec 26 00:19:51 Soundwave kernel: [22717.160004] [] ? taskq_thread+0x1f4/0x3b0 [spl]
Dec 26 00:19:51 Soundwave kernel: [22717.160004] [] ? default_wake_function+0x0/0x20
Dec 26 00:19:51 Soundwave kernel: [22717.160004] [] ? taskq_thread+0x0/0x3b0 [spl]
Dec 26 00:19:51 Soundwave kernel: [22717.160004] [] ? kthread+0x96/0xa0
Dec 26 00:19:51 Soundwave kernel: [22717.160004] [] ? child_rip+0xa/0x20
Dec 26 00:19:51 Soundwave kernel: [22717.160004] [] ? kthread+0x0/0xa0
Dec 26 00:19:51 Soundwave kernel: [22717.160004] [] ? child_rip+0x0/0x20
Dec 26 00:20:57 Soundwave kernel: [22782.659999] BUG: soft lockup - CPU#0 stuck for 61s! [z_null_iss/0:5651]
Dec 26 00:20:57 Soundwave kernel: [22782.660004] Modules linked in: nls_utf8 hfsplus pci_stub vboxpci vboxnetadp vboxnetflt vboxdrv iptable_filter ip_tables x_tables binfmt_misc ppdev snd_hda_codec_atihdmi fbcon tileblit font bitblit softcursor vga16fb vgastate snd_hda_codec_via snd_seq_dummy snd_seq_oss snd_seq_midi snd_hda_intel snd_rawmidi snd_hda_codec snd_hwdep radeon snd_seq_midi_event snd_pcm_oss snd_seq ttm snd_mixer_oss drm_kms_helper snd_pcm snd_seq_device dell_wmi drm i2c_algo_bit snd_timer dcdbas snd psmouse serio_raw edac_core edac_mce_amd i2c_piix4 soundcore snd_page_alloc shpchp lp parport zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl zlib_deflate usbhid hid usb_storage pata_atiixp ahci r8169 mii
Dec 26 00:20:57 Soundwave kernel: [22782.660004] CPU 0:
Dec 26 00:20:57 Soundwave kernel: [22782.660004] Modules linked in: nls_utf8 hfsplus pci_stub vboxpci vboxnetadp vboxnetflt vboxdrv iptable_filter ip_tables x_tables binfmt_misc ppdev snd_hda_codec_atihdmi fbcon tileblit font bitblit softcursor vga16fb vgastate snd_hda_codec_via snd_seq_dummy snd_seq_oss snd_seq_midi snd_hda_intel snd_rawmidi snd_hda_codec snd_hwdep radeon snd_seq_midi_event snd_pcm_oss snd_seq ttm snd_mixer_oss drm_kms_helper snd_pcm snd_seq_device dell_wmi drm i2c_algo_bit snd_timer dcdbas snd psmouse serio_raw edac_core edac_mce_amd i2c_piix4 soundcore snd_page_alloc shpchp lp parport zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl zlib_deflate usbhid hid usb_storage pata_atiixp ahci r8169 mii
Dec 26 00:20:57 Soundwave kernel: [22782.660004] Pid: 5651, comm: z_null_iss/0 Tainted: P 2.6.32-37-server #81-Ubuntu Inspiron 546S
Dec 26 00:20:57 Soundwave kernel: [22782.660004] RIP: 0010:[] [] __ticket_spin_lock+0x1c/0x20
Dec 26 00:20:57 Soundwave kernel: [22782.660004] RSP: 0018:ffff8801eca1fd60 EFLAGS: 00000202
Dec 26 00:20:57 Soundwave kernel: [22782.660004] RAX: 0000000000000000 RBX: ffff8801eca1fd60 RCX: ffff8801201d8b68
Dec 26 00:20:57 Soundwave kernel: [22782.660004] RDX: 0000000000000002 RSI: 0000000000000282 RDI: ffff8801201d8b2c
Dec 26 00:20:57 Soundwave kernel: [22782.660004] RBP: ffffffff81013c6e R08: ffff880217502e00 R09: 0000000000000001
Dec 26 00:20:57 Soundwave kernel: [22782.660004] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
Dec 26 00:20:57 Soundwave kernel: [22782.660004] R13: 0000000000000000 R14: ffff8801eca1fd50 R15: ffffffff81013ace
Dec 26 00:20:57 Soundwave kernel: [22782.660004] FS: 00007f1a620a4700(0000) GS:ffff880008c00000(0000) knlGS:0000000000000000
Dec 26 00:20:57 Soundwave kernel: [22782.660004] CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
Dec 26 00:20:57 Soundwave kernel: [22782.660004] CR2: 000000000235b808 CR3: 000000011c0a5000 CR4: 00000000000006f0
Dec 26 00:20:57 Soundwave kernel: [22782.660004] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Dec 26 00:20:57 Soundwave kernel: [22782.660004] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Dec 26 00:20:57 Soundwave kernel: [22782.660004] Call Trace:
Dec 26 00:20:57 Soundwave kernel: [22782.660004] [] ? _spin_lock+0xe/0x20
Dec 26 00:20:57 Soundwave kernel: [22782.660004] [] ? __mutex_unlock_slowpath+0x25/0x60
Dec 26 00:20:57 Soundwave kernel: [22782.660004] [] ? mutex_unlock+0x1b/0x20
Dec 26 00:20:57 Soundwave kernel: [22782.660004] [] ? zio_done+0x4b5/0xc00 [zfs]
Dec 26 00:20:57 Soundwave kernel: [22782.660004] [] ? zio_execute+0x99/0xf0 [zfs]
Dec 26 00:20:57 Soundwave kernel: [22782.660004] [] ? taskq_thread+0x1f4/0x3b0 [spl]
Dec 26 00:20:57 Soundwave kernel: [22782.660004] [] ? default_wake_function+0x0/0x20
Dec 26 00:20:57 Soundwave kernel: [22782.660004] [] ? taskq_thread+0x0/0x3b0 [spl]
Dec 26 00:20:57 Soundwave kernel: [22782.660004] [] ? kthread+0x96/0xa0
Dec 26 00:20:57 Soundwave kernel: [22782.660004] [] ? child_rip+0xa/0x20
Dec 26 00:20:57 Soundwave kernel: [22782.660004] [] ? kthread+0x0/0xa0
Dec 26 00:20:57 Soundwave kernel: [22782.660004] [] ? child_rip+0x0/0x20
Dec 26 00:21:15 Soundwave kernel: [22800.742567] INFO: task deluged:2933 blocked for more than 120 seconds.
Dec 26 00:21:15 Soundwave kernel: [22800.742573] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 26 00:21:15 Soundwave kernel: [22800.742579] deluged D 00000000ffffffff 0 2933 1 0x00000000
Dec 26 00:21:15 Soundwave kernel: [22800.742589] ffff8801fdef7a78 0000000000000082 0000000000015f00 0000000000015f00
Dec 26 00:21:15 Soundwave kernel: [22800.742598] ffff8801fddb83d0 ffff8801fdef7fd8 0000000000015f00 ffff8801fddb8000
Dec 26 00:21:15 Soundwave kernel: [22800.742605] 0000000000015f00 ffff8801fdef7fd8 0000000000015f00 ffff8801fddb83d0
Dec 26 00:21:15 Soundwave kernel: [22800.742612] Call Trace:
Dec 26 00:21:15 Soundwave kernel: [22800.742655] [] cv_wait_common+0x78/0xe0 [spl]
Dec 26 00:21:15 Soundwave kernel: [22800.742666] [] ? autoremove_wake_function+0x0/0x40
Dec 26 00:21:15 Soundwave kernel: [22800.742686] [] __cv_wait+0x13/0x20 [spl]
Dec 26 00:21:15 Soundwave kernel: [22800.742767] [] txg_wait_open+0x7b/0xa0 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.742820] [] dmu_tx_wait+0xed/0xf0 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.742885] [] zfs_write+0x3be/0xc90 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.742949] [] zpl_write_common+0x52/0x70 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.743010] [] zpl_write+0x68/0xa0 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.743071] [] ? zpl_write+0x0/0xa0 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.743080] [] do_loop_readv_writev+0x59/0x90
Dec 26 00:21:15 Soundwave kernel: [22800.743086] [] do_readv_writev+0x1de/0x1f0
Dec 26 00:21:15 Soundwave kernel: [22800.743093] [] ? futex_wake+0x112/0x130
Dec 26 00:21:15 Soundwave kernel: [22800.743099] [] ? do_futex+0xb8/0x1b0
Dec 26 00:21:15 Soundwave kernel: [22800.743105] [] vfs_writev+0x48/0x60
Dec 26 00:21:15 Soundwave kernel: [22800.743110] [] sys_writev+0x51/0xb0
Dec 26 00:21:15 Soundwave kernel: [22800.743118] [] system_call_fastpath+0x16/0x1b
Dec 26 00:21:15 Soundwave kernel: [22800.743147] INFO: task txg_sync:5813 blocked for more than 120 seconds.
Dec 26 00:21:15 Soundwave kernel: [22800.743151] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 26 00:21:15 Soundwave kernel: [22800.743155] txg_sync D 00000000ffffffff 0 5813 2 0x00000000
Dec 26 00:21:15 Soundwave kernel: [22800.743162] ffff8801e8dedb30 0000000000000046 0000000000015f00 0000000000015f00
Dec 26 00:21:15 Soundwave kernel: [22800.743169] ffff8801ec4f48d0 ffff8801e8dedfd8 0000000000015f00 ffff8801ec4f4500
Dec 26 00:21:15 Soundwave kernel: [22800.743176] 0000000000015f00 ffff8801e8dedfd8 0000000000015f00 ffff8801ec4f48d0
Dec 26 00:21:15 Soundwave kernel: [22800.743182] Call Trace:
Dec 26 00:21:15 Soundwave kernel: [22800.743191] [] __mutex_lock_slowpath+0x107/0x190
Dec 26 00:21:15 Soundwave kernel: [22800.743198] [] mutex_lock+0x23/0x50
Dec 26 00:21:15 Soundwave kernel: [22800.743217] [] cv_wait_common+0x80/0xe0 [spl]
Dec 26 00:21:15 Soundwave kernel: [22800.743223] [] ? autoremove_wake_function+0x0/0x40
Dec 26 00:21:15 Soundwave kernel: [22800.743240] [] __cv_wait+0x13/0x20 [spl]
Dec 26 00:21:15 Soundwave kernel: [22800.743300] [] zio_wait+0xeb/0x160 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.743362] [] vdev_label_sync_list+0x15f/0x170 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.743425] [] vdev_config_sync+0x11f/0x160 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.743484] [] spa_sync+0x726/0x9a0 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.743491] [] ? autoremove_wake_function+0x16/0x40
Dec 26 00:21:15 Soundwave kernel: [22800.743498] [] ? __wake_up+0x53/0x70
Dec 26 00:21:15 Soundwave kernel: [22800.743559] [] txg_sync_thread+0x225/0x3b0 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.743621] [] ? txg_sync_thread+0x0/0x3b0 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.743638] [] thread_generic_wrapper+0x68/0x80 [spl]
Dec 26 00:21:15 Soundwave kernel: [22800.743653] [] ? thread_generic_wrapper+0x0/0x80 [spl]
Dec 26 00:21:15 Soundwave kernel: [22800.743659] [] kthread+0x96/0xa0
Dec 26 00:21:15 Soundwave kernel: [22800.743665] [] child_rip+0xa/0x20
Dec 26 00:21:15 Soundwave kernel: [22800.743671] [] ? kthread+0x0/0xa0
Dec 26 00:21:15 Soundwave kernel: [22800.743676] [] ? child_rip+0x0/0x20
Dec 26 00:21:15 Soundwave kernel: [22800.743683] INFO: task afpd:17096 blocked for more than 120 seconds.
Dec 26 00:21:15 Soundwave kernel: [22800.743686] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 26 00:21:15 Soundwave kernel: [22800.743690] afpd D 00000000ffffffff 0 17096 15761 0x00000004
Dec 26 00:21:15 Soundwave kernel: [22800.743697] ffff8801a0dddb78 0000000000000082 0000000000015f00 0000000000015f00
Dec 26 00:21:15 Soundwave kernel: [22800.743703] ffff8801e77b5fd0 ffff8801a0dddfd8 0000000000015f00 ffff8801e77b5c00
Dec 26 00:21:15 Soundwave kernel: [22800.743709] 0000000000015f00 ffff8801a0dddfd8 0000000000015f00 ffff8801e77b5fd0
Dec 26 00:21:15 Soundwave kernel: [22800.743715] Call Trace:
Dec 26 00:21:15 Soundwave kernel: [22800.743732] [] cv_wait_common+0x78/0xe0 [spl]
Dec 26 00:21:15 Soundwave kernel: [22800.743738] [] ? autoremove_wake_function+0x0/0x40
Dec 26 00:21:15 Soundwave kernel: [22800.743755] [] __cv_wait+0x13/0x20 [spl]
Dec 26 00:21:15 Soundwave kernel: [22800.743814] [] txg_wait_open+0x7b/0xa0 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.743865] [] dmu_tx_wait+0xed/0xf0 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.743927] [] zfs_write+0x3be/0xc90 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.743989] [] zpl_write_common+0x52/0x70 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.744050] [] zpl_write+0x68/0xa0 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.744059] [] ? security_file_permission+0x16/0x20
Dec 26 00:21:15 Soundwave kernel: [22800.744065] [] vfs_write+0xb8/0x1a0
Dec 26 00:21:15 Soundwave kernel: [22800.744071] [] sys_pwrite64+0x82/0xa0
Dec 26 00:21:15 Soundwave kernel: [22800.744077] [] system_call_fastpath+0x16/0x1b
Dec 26 00:21:15 Soundwave kernel: [22800.744089] INFO: task zpool:21430 blocked for more than 120 seconds.
Dec 26 00:21:15 Soundwave kernel: [22800.744092] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 26 00:21:15 Soundwave kernel: [22800.744096] zpool D 0000000000000000 0 21430 21027 0x00000000
Dec 26 00:21:15 Soundwave kernel: [22800.744102] ffff880132b5fc28 0000000000000086 0000000000015f00 0000000000015f00
Dec 26 00:21:15 Soundwave kernel: [22800.744108] ffff88020442c8d0 ffff880132b5ffd8 0000000000015f00 ffff88020442c500
Dec 26 00:21:15 Soundwave kernel: [22800.744114] 0000000000015f00 ffff880132b5ffd8 0000000000015f00 ffff88020442c8d0
Dec 26 00:21:15 Soundwave kernel: [22800.744120] Call Trace:
Dec 26 00:21:15 Soundwave kernel: [22800.744137] [] __taskq_create+0x2b5/0x3a0 [spl]
Dec 26 00:21:15 Soundwave kernel: [22800.744144] [] ? autoremove_wake_function+0x0/0x40
Dec 26 00:21:15 Soundwave kernel: [22800.744204] [] spa_activate+0x251/0x300 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.744267] [] spa_open_common+0x11d/0x380 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.744328] [] spa_get_stats+0x49/0x270 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.744336] [] ? __kmalloc+0x14e/0x1a0
Dec 26 00:21:15 Soundwave kernel: [22800.744397] [] zfs_ioc_pool_stats+0x31/0x70 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.744459] [] zfsdev_ioctl+0xfd/0x1c0 [zfs]
Dec 26 00:21:15 Soundwave kernel: [22800.744467] [] vfs_ioctl+0x22/0xa0
Dec 26 00:21:15 Soundwave kernel: [22800.744473] [] do_vfs_ioctl+0x81/0x410
Dec 26 00:21:15 Soundwave kernel: [22800.744480] [] ? hrtimer_start_range_ns+0x14/0x20
Dec 26 00:21:15 Soundwave kernel: [22800.744486] [] sys_ioctl+0x81/0xa0
Dec 26 00:21:15 Soundwave kernel: [22800.744492] [] ? do_device_not_available+0xe/0x10
Dec 26 00:21:15 Soundwave kernel: [22800.744499] [] system_call_fastpath+0x16/0x1b
Dec 26 00:22:02 Soundwave kernel: [22848.159998] BUG: soft lockup - CPU#0 stuck for 61s! [z_null_iss/0:5651]
Dec 26 00:22:02 Soundwave kernel: [22848.160002] Modules linked in: nls_utf8 hfsplus pci_stub vboxpci vboxnetadp vboxnetflt vboxdrv iptable_filter ip_tables x_tables binfmt_misc ppdev snd_hda_codec_atihdmi fbcon tileblit font bitblit softcursor vga16fb vgastate snd_hda_codec_via snd_seq_dummy snd_seq_oss snd_seq_midi snd_hda_intel snd_rawmidi snd_hda_codec snd_hwdep radeon snd_seq_midi_event snd_pcm_oss snd_seq ttm snd_mixer_oss drm_kms_helper snd_pcm snd_seq_device dell_wmi drm i2c_algo_bit snd_timer dcdbas snd psmouse serio_raw edac_core edac_mce_amd i2c_piix4 soundcore snd_page_alloc shpchp lp parport zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl zlib_deflate usbhid hid usb_storage pata_atiixp ahci r8169 mii
Dec 26 00:22:02 Soundwave kernel: [22848.160002] CPU 0:
Dec 26 00:22:02 Soundwave kernel: [22848.160002] Modules linked in: nls_utf8 hfsplus pci_stub vboxpci vboxnetadp vboxnetflt vboxdrv iptable_filter ip_tables x_tables binfmt_misc ppdev snd_hda_codec_atihdmi fbcon tileblit font bitblit softcursor vga16fb vgastate snd_hda_codec_via snd_seq_dummy snd_seq_oss snd_seq_midi snd_hda_intel snd_rawmidi snd_hda_codec snd_hwdep radeon snd_seq_midi_event snd_pcm_oss snd_seq ttm snd_mixer_oss drm_kms_helper snd_pcm snd_seq_device dell_wmi drm i2c_algo_bit snd_timer dcdbas snd psmouse serio_raw edac_core edac_mce_amd i2c_piix4 soundcore snd_page_alloc shpchp lp parport zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl zlib_deflate usbhid hid usb_storage pata_atiixp ahci r8169 mii
Dec 26 00:22:02 Soundwave kernel: [22848.160002] Pid: 5651, comm: z_null_iss/0 Tainted: P 2.6.32-37-server #81-Ubuntu Inspiron 546S
Dec 26 00:22:02 Soundwave kernel: [22848.160002] RIP: 0010:[] [] __ticket_spin_lock+0x1c/0x20
Dec 26 00:22:02 Soundwave kernel: [22848.160002] RSP: 0018:ffff8801eca1fd60 EFLAGS: 00000202
Dec 26 00:22:02 Soundwave kernel: [22848.160002] RAX: 0000000000000000 RBX: ffff8801eca1fd60 RCX: ffff8801201d8b68
Dec 26 00:22:02 Soundwave kernel: [22848.160002] RDX: 0000000000000002 RSI: 0000000000000282 RDI: ffff8801201d8b2c
Dec 26 00:22:02 Soundwave kernel: [22848.160002] RBP: ffffffff81013c6e R08: ffff880217502e00 R09: 0000000000000001
Dec 26 00:22:02 Soundwave kernel: [22848.160002] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
Dec 26 00:22:02 Soundwave kernel: [22848.160002] R13: 0000000000000000 R14: ffff8801eca1fd50 R15: ffffffff81013ace
Dec 26 00:22:02 Soundwave kernel: [22848.160002] FS: 00007f1a620a4700(0000) GS:ffff880008c00000(0000) knlGS:0000000000000000
Dec 26 00:22:02 Soundwave kernel: [22848.160002] CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
Dec 26 00:22:02 Soundwave kernel: [22848.160002] CR2: 000000000235b808 CR3: 000000011c0a5000 CR4: 00000000000006f0
Dec 26 00:22:02 Soundwave kernel: [22848.160002] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Dec 26 00:22:02 Soundwave kernel: [22848.160002] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Dec 26 00:22:02 Soundwave kernel: [22848.160002] Call Trace:
Dec 26 00:22:02 Soundwave kernel: [22848.160002] [] ? _spin_lock+0xe/0x20
Dec 26 00:22:02 Soundwave kernel: [22848.160002] [] ? __mutex_unlock_slowpath+0x25/0x60
Dec 26 00:22:02 Soundwave kernel: [22848.160002] [] ? mutex_unlock+0x1b/0x20
Dec 26 00:22:02 Soundwave kernel: [22848.160002] [] ? zio_done+0x4b5/0xc00 [zfs]
Dec 26 00:22:02 Soundwave kernel: [22848.160002] [] ? zio_execute+0x99/0xf0 [zfs]
Dec 26 00:22:02 Soundwave kernel: [22848.160002] [] ? taskq_thread+0x1f4/0x3b0 [spl]
Dec 26 00:22:02 Soundwave kernel: [22848.160002] [] ? default_wake_function+0x0/0x20
Dec 26 00:22:02 Soundwave kernel: [22848.160002] [] ? taskq_thread+0x0/0x3b0 [spl]
Dec 26 00:22:02 Soundwave kernel: [22848.160002] [] ? kthread+0x96/0xa0
Dec 26 00:22:02 Soundwave kernel: [22848.160002] [] ? child_rip+0xa/0x20
Dec 26 00:22:02 Soundwave kernel: [22848.160002] [] ? kthread+0x0/0xa0
Dec 26 00:22:02 Soundwave kernel: [22848.160002] [] ? child_rip+0x0/0x20
Dec 26 00:23:08 Soundwave kernel: [22913.659999] BUG: soft lockup - CPU#0 stuck for 61s! [z_null_iss/0:5651]
Dec 26 00:23:08 Soundwave kernel: [22913.660002] Modules linked in: nls_utf8 hfsplus pci_stub vboxpci vboxnetadp vboxnetflt vboxdrv iptable_filter ip_tables x_tables binfmt_misc ppdev snd_hda_codec_atihdmi fbcon tileblit font bitblit softcursor vga16fb vgastate snd_hda_codec_via snd_seq_dummy snd_seq_oss snd_seq_midi snd_hda_intel snd_rawmidi snd_hda_codec snd_hwdep radeon snd_seq_midi_event snd_pcm_oss snd_seq ttm snd_mixer_oss drm_kms_helper snd_pcm snd_seq_device dell_wmi drm i2c_algo_bit snd_timer dcdbas snd psmouse serio_raw edac_core edac_mce_amd i2c_piix4 soundcore snd_page_alloc shpchp lp parport zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl zlib_deflate usbhid hid usb_storage pata_atiixp ahci r8169 mii
Dec 26 00:23:08 Soundwave kernel: [22913.660002] CPU 0:
Dec 26 00:23:08 Soundwave kernel: [22913.660002] Modules linked in: nls_utf8 hfsplus pci_stub vboxpci vboxnetadp vboxnetflt vboxdrv iptable_filter ip_tables x_tables binfmt_misc ppdev snd_hda_codec_atihdmi fbcon tileblit font bitblit softcursor vga16fb vgastate snd_hda_codec_via snd_seq_dummy snd_seq_oss snd_seq_midi snd_hda_intel snd_rawmidi snd_hda_codec snd_hwdep radeon snd_seq_midi_event snd_pcm_oss snd_seq ttm snd_mixer_oss drm_kms_helper snd_pcm snd_seq_device dell_wmi drm i2c_algo_bit snd_timer dcdbas snd psmouse serio_raw edac_core edac_mce_amd i2c_piix4 soundcore snd_page_alloc shpchp lp parport zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl zlib_deflate usbhid hid usb_storage pata_atiixp ahci r8169 mii
Dec 26 00:23:08 Soundwave kernel: [22913.660002] Pid: 5651, comm: z_null_iss/0 Tainted: P 2.6.32-37-server #81-Ubuntu Inspiron 546S
Dec 26 00:23:08 Soundwave kernel: [22913.660002] RIP: 0010:[] [] __ticket_spin_lock+0x19/0x20
Dec 26 00:23:08 Soundwave kernel: [22913.660002] RSP: 0018:ffff8801eca1fd60 EFLAGS: 00000202
Dec 26 00:23:08 Soundwave kernel: [22913.660002] RAX: 0000000000000000 RBX: ffff8801eca1fd60 RCX: ffff8801201d8b68
Dec 26 00:23:08 Soundwave kernel: [22913.660002] RDX: 0000000000000002 RSI: 0000000000000282 RDI: ffff8801201d8b2c
Dec 26 00:23:08 Soundwave kernel: [22913.660002] RBP: ffffffff81013c6e R08: ffff880217502e00 R09: 0000000000000001
Dec 26 00:23:08 Soundwave kernel: [22913.660002] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
Dec 26 00:23:08 Soundwave kernel: [22913.660002] R13: 0000000000000000 R14: ffff8801eca1fd50 R15: ffffffff81013ace
Dec 26 00:23:08 Soundwave kernel: [22913.660002] FS: 00007f1a620a4700(0000) GS:ffff880008c00000(0000) knlGS:0000000000000000
Dec 26 00:23:08 Soundwave kernel: [22913.660002] CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
Dec 26 00:23:08 Soundwave kernel: [22913.660002] CR2: 000000000235b808 CR3: 000000011c0a5000 CR4: 00000000000006f0
Dec 26 00:23:08 Soundwave kernel: [22913.660002] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Dec 26 00:23:08 Soundwave kernel: [22913.660002] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Dec 26 00:23:08 Soundwave kernel: [22913.660002] Call Trace:
Dec 26 00:23:08 Soundwave kernel: [22913.660002] [] ? _spin_lock+0xe/0x20
Dec 26 00:23:08 Soundwave kernel: [22913.660002] [] ? __mutex_unlock_slowpath+0x25/0x60
Dec 26 00:23:08 Soundwave kernel: [22913.660002] [] ? mutex_unlock+0x1b/0x20
Dec 26 00:23:08 Soundwave kernel: [22913.660002] [] ? zio_done+0x4b5/0xc00 [zfs]
Dec 26 00:23:08 Soundwave kernel: [22913.660002] [] ? zio_execute+0x99/0xf0 [zfs]
Dec 26 00:23:08 Soundwave kernel: [22913.660002] [] ? taskq_thread+0x1f4/0x3b0 [spl]
Dec 26 00:23:08 Soundwave kernel: [22913.660002] [] ? default_wake_function+0x0/0x20
Dec 26 00:23:08 Soundwave kernel: [22913.660002] [] ? taskq_thread+0x0/0x3b0 [spl]
Dec 26 00:23:08 Soundwave kernel: [22913.660002] [] ? kthread+0x96/0xa0
Dec 26 00:23:08 Soundwave kernel: [22913.660002] [] ? child_rip+0xa/0x20
Dec 26 00:23:08 Soundwave kernel: [22913.660002] [] ? kthread+0x0/0xa0
Dec 26 00:23:08 Soundwave kernel: [22913.660002] [] ? child_rip+0x0/0x20
Dec 26 00:23:15 Soundwave kernel: [22920.741300] INFO: task deluged:2933 blocked for more than 120 seconds.
Dec 26 00:23:15 Soundwave kernel: [22920.741307] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 26 00:23:15 Soundwave kernel: [22920.741313] deluged D 00000000ffffffff 0 2933 1 0x00000000
Dec 26 00:23:15 Soundwave kernel: [22920.741322] ffff8801fdef7a78 0000000000000082 0000000000015f00 0000000000015f00
Dec 26 00:23:15 Soundwave kernel: [22920.741331] ffff8801fddb83d0 ffff8801fdef7fd8 0000000000015f00 ffff8801fddb8000
Dec 26 00:23:15 Soundwave kernel: [22920.741338] 0000000000015f00 ffff8801fdef7fd8 0000000000015f00 ffff8801fddb83d0
Dec 26 00:23:15 Soundwave kernel: [22920.741345] Call Trace:
Dec 26 00:23:15 Soundwave kernel: [22920.741387] [] cv_wait_common+0x78/0xe0 [spl]
Dec 26 00:23:15 Soundwave kernel: [22920.741399] [] ? autoremove_wake_function+0x0/0x40
Dec 26 00:23:15 Soundwave kernel: [22920.741420] [] __cv_wait+0x13/0x20 [spl]
Dec 26 00:23:15 Soundwave kernel: [22920.741501] [] txg_wait_open+0x7b/0xa0 [zfs]
Dec 26 00:23:15 Soundwave kernel: [22920.741557] [] dmu_tx_wait+0xed/0xf0 [zfs]
Dec 26 00:23:15 Soundwave kernel: [22920.741628] [] zfs_write+0x3be/0xc90 [zfs]
Dec 26 00:23:15 Soundwave kernel: [22920.741692] [] zpl_write_common+0x52/0x70 [zfs]
Dec 26 00:23:15 Soundwave kernel: [22920.741753] [] zpl_write+0x68/0xa0 [zfs]
Dec 26 00:23:15 Soundwave kernel: [22920.741816] [] ? zpl_write+0x0/0xa0 [zfs]
Dec 26 00:23:15 Soundwave kernel: [22920.741825] [] do_loop_readv_writev+0x59/0x90
Dec 26 00:23:15 Soundwave kernel: [22920.741832] [] do_readv_writev+0x1de/0x1f0
Dec 26 00:23:15 Soundwave kernel: [22920.741838] [] ? futex_wake+0x112/0x130
Dec 26 00:23:15 Soundwave kernel: [22920.741844] [] ? do_futex+0xb8/0x1b0
Dec 26 00:23:15 Soundwave kernel: [22920.741850] [] vfs_writev+0x48/0x60
Dec 26 00:23:15 Soundwave kernel: [22920.741858] [] sys_writev+0x51/0xb0
Dec 26 00:23:15 Soundwave kernel: [22920.741868] [] system_call_fastpath+0x16/0x1b
Dec 26 00:23:15 Soundwave kernel: [22920.741898] INFO: task txg_sync:5813 blocked for more than 120 seconds.
Dec 26 00:23:15 Soundwave kernel: [22920.741902] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 26 00:23:15 Soundwave kernel: [22920.741906] txg_sync D 00000000ffffffff 0 5813 2 0x00000000
Dec 26 00:23:15 Soundwave kernel: [22920.741916] ffff8801e8dedb30 0000000000000046 0000000000015f00 0000000000015f00
Dec 26 00:23:15 Soundwave kernel: [22920.741922] ffff8801ec4f48d0 ffff8801e8dedfd8 0000000000015f00 ffff8801ec4f4500
Dec 26 00:23:15 Soundwave kernel: [22920.741931] 0000000000015f00 ffff8801e8dedfd8 0000000000015f00 ffff8801ec4f48d0
Dec 26 00:23:15 Soundwave kernel: [22920.741937] Call Trace:
Dec 26 00:23:15 Soundwave kernel: [22920.741947] [] __mutex_lock_slowpath+0x107/0x190
Dec 26 00:23:15 Soundwave kernel: [22920.741954] [] mutex_lock+0x23/0x50
Dec 26 00:23:15 Soundwave kernel: [22920.741972] [] cv_wait_common+0x80/0xe0 [spl]
Dec 26 00:23:15 Soundwave kernel: [22920.741979] [] ? autoremove_wake_function+0x0/0x40
Dec 26 00:23:15 Soundwave kernel: [22920.741998] [] __cv_wait+0x13/0x20 [spl]
Dec 26 00:23:15 Soundwave kernel: [22920.742064] [] zio_wait+0xeb/0x160 [zfs]
Dec 26 00:23:15 Soundwave kernel: [22920.742129] [] vdev_label_sync_list+0x15f/0x170 [zfs]
Dec 26 00:23:15 Soundwave kernel: [22920.742194] [] vdev_config_sync+0x11f/0x160 [zfs]
Dec 26 00:23:15 Soundwave kernel: [22920.742256] [] spa_sync+0x726/0x9a0 [zfs]
Dec 26 00:23:15 Soundwave kernel: [22920.742263] [] ? autoremove_wake_function+0x16/0x40
Dec 26 00:23:15 Soundwave kernel: [22920.742272] [] ? __wake_up+0x53/0x70
Dec 26 00:23:15 Soundwave kernel: [22920.742333] [] txg_sync_thread+0x225/0x3b0 [zfs]
Dec 26 00:23:15 Soundwave kernel: [22920.742394] [] ? txg_sync_thread+0x0/0x3b0 [zfs]
Dec 26 00:23:15 Soundwave kernel: [22920.742412] [] thread_generic_wrapper+0x68/0x80 [spl]
Dec 26 00:23:15 Soundwave kernel: [22920.742429] [] ? thread_generic_wrapper+0x0/0x80 [spl]
Dec 26 00:23:15 Soundwave kernel: [22920.742435] [] kthread+0x96/0xa0
Dec 26 00:23:15 Soundwave kernel: [22920.742442] [] child_rip+0xa/0x20
Dec 26 00:23:15 Soundwave kernel: [22920.742448] [] ? kthread+0x0/0xa0
Dec 26 00:23:15 Soundwave kernel: [22920.742453] [] ? child_rip+0x0/0x20
Dec 26 00:24:13 Soundwave kernel: [22979.149996] BUG: soft lockup - CPU#0 stuck for 61s! [z_null_iss/0:5651]
Dec 26 00:24:13 Soundwave kernel: [22979.150002] Modules linked in: nls_utf8 hfsplus pci_stub vboxpci vboxnetadp vboxnetflt vboxdrv iptable_filter ip_tables x_tables binfmt_misc ppdev snd_hda_codec_atihdmi fbcon tileblit font bitblit softcursor vga16fb vgastate snd_hda_codec_via snd_seq_dummy snd_seq_oss snd_seq_midi snd_hda_intel snd_rawmidi snd_hda_codec snd_hwdep radeon snd_seq_midi_event snd_pcm_oss snd_seq ttm snd_mixer_oss drm_kms_helper snd_pcm snd_seq_device dell_wmi drm i2c_algo_bit snd_timer dcdbas snd psmouse serio_raw edac_core edac_mce_amd i2c_piix4 soundcore snd_page_alloc shpchp lp parport zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl zlib_deflate usbhid hid usb_storage pata_atiixp ahci r8169 mii
Dec 26 00:24:13 Soundwave kernel: [22979.150032] CPU 0:
Dec 26 00:24:13 Soundwave kernel: [22979.150032] Modules linked in: nls_utf8 hfsplus pci_stub vboxpci vboxnetadp vboxnetflt vboxdrv iptable_filter ip_tables x_tables binfmt_misc ppdev snd_hda_codec_atihdmi fbcon tileblit font bitblit softcursor vga16fb vgastate snd_hda_codec_via snd_seq_dummy snd_seq_oss snd_seq_midi snd_hda_intel snd_rawmidi snd_hda_codec snd_hwdep radeon snd_seq_midi_event snd_pcm_oss snd_seq ttm snd_mixer_oss drm_kms_helper snd_pcm snd_seq_device dell_wmi drm i2c_algo_bit snd_timer dcdbas snd psmouse serio_raw edac_core edac_mce_amd i2c_piix4 soundcore snd_page_alloc shpchp lp parport zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl zlib_deflate usbhid hid usb_storage pata_atiixp ahci r8169 mii
Dec 26 00:24:13 Soundwave kernel: [22979.150032] Pid: 5651, comm: z_null_iss/0 Tainted: P 2.6.32-37-server #81-Ubuntu Inspiron 546S
Dec 26 00:24:13 Soundwave kernel: [22979.150032] RIP: 0010:[] [] __ticket_spin_lock+0x1c/0x20
Dec 26 00:24:13 Soundwave kernel: [22979.150032] RSP: 0018:ffff8801eca1fd60 EFLAGS: 00000202
Dec 26 00:24:13 Soundwave kernel: [22979.150032] RAX: 0000000000000000 RBX: ffff8801eca1fd60 RCX: ffff8801201d8b68
Dec 26 00:24:13 Soundwave kernel: [22979.150032] RDX: 0000000000000002 RSI: 0000000000000282 RDI: ffff8801201d8b2c
Dec 26 00:24:13 Soundwave kernel: [22979.150032] RBP: ffffffff81013c6e R08: ffff880217502e00 R09: 0000000000000001
Dec 26 00:24:13 Soundwave kernel: [22979.150032] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
Dec 26 00:24:13 Soundwave kernel: [22979.150032] R13: 0000000000000000 R14: ffff8801eca1fd50 R15: ffffffff81013ace
Dec 26 00:24:13 Soundwave kernel: [22979.150032] FS: 00007f1a620a4700(0000) GS:ffff880008c00000(0000) knlGS:0000000000000000
Dec 26 00:24:13 Soundwave kernel: [22979.150032] CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
Dec 26 00:24:13 Soundwave kernel: [22979.150032] CR2: 000000000235b808 CR3: 000000011c0a5000 CR4: 00000000000006f0
Dec 26 00:24:13 Soundwave kernel: [22979.150032] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Dec 26 00:24:13 Soundwave kernel: [22979.150032] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Dec 26 00:24:13 Soundwave kernel: [22979.150032] Call Trace:
Dec 26 00:24:13 Soundwave kernel: [22979.150032] [] ? _spin_lock+0xe/0x20
Dec 26 00:24:13 Soundwave kernel: [22979.150032] [] ? __mutex_unlock_slowpath+0x25/0x60
Dec 26 00:24:13 Soundwave kernel: [22979.150032] [] ? mutex_unlock+0x1b/0x20
Dec 26 00:24:13 Soundwave kernel: [22979.150032] [] ? zio_done+0x4b5/0xc00 [zfs]
Dec 26 00:24:13 Soundwave kernel: [22979.150032] [] ? zio_execute+0x99/0xf0 [zfs]
Dec 26 00:24:13 Soundwave kernel: [22979.150032] [] ? taskq_thread+0x1f4/0x3b0 [spl]
Dec 26 00:24:13 Soundwave kernel: [22979.150032] [] ? default_wake_function+0x0/0x20
Dec 26 00:24:13 Soundwave kernel: [22979.150032] [] ? taskq_thread+0x0/0x3b0 [spl]
Dec 26 00:24:13 Soundwave kernel: [22979.150032] [] ? kthread+0x96/0xa0
Dec 26 00:24:13 Soundwave kernel: [22979.150032] [] ? child_rip+0xa/0x20
Dec 26 00:24:13 Soundwave kernel: [22979.150032] [] ? kthread+0x0/0xa0
Dec 26 00:24:13 Soundwave kernel: [22979.150032] [

behlendorf · 2012-01-19T19:16:06Z

I'm not sure there's a bug here. The above warnings are just advisory that things are going slowly. Did the system lock up for the transfer fail?

behlendorf · 2012-03-16T03:43:27Z

This is actually a duplicate of issue #496. I've merged in a workaround for that issue for now.

The below excerpt of a backtrace is from a ztest failure when running ZoL's ztest. /openzfs#453 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#454 0x00007f03c806106e in vdev_queue_io (zio=zio@entry=0x7f0350003de0) at ../../module/zfs/vdev_queue.c:747 /openzfs#455 0x00007f03c80818c1 in zio_vdev_io_start (zio=0x7f0350003de0) at ../../module/zfs/zio.c:2659 /openzfs#456 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003de0) at ../../module/zfs/zio.c:1399 /openzfs#457 zio_nowait (zio=0x7f0350003de0) at ../../module/zfs/zio.c:1456 /openzfs#458 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350003a10) at ../../module/zfs/vdev_mirror.c:374 /openzfs#459 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003a10) at ../../module/zfs/zio.c:1399 /openzfs#460 zio_nowait (zio=0x7f0350003a10) at ../../module/zfs/zio.c:1456 /openzfs#461 0x00007f03c806464c in vdev_raidz_io_start (zio=0x7f0350003380) at ../../module/zfs/vdev_raidz.c:1607 /openzfs#462 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003380) at ../../module/zfs/zio.c:1399 /openzfs#463 zio_nowait (zio=0x7f0350003380) at ../../module/zfs/zio.c:1456 /openzfs#464 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350002fb0) at ../../module/zfs/vdev_mirror.c:374 /openzfs#465 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002fb0) at ../../module/zfs/zio.c:1399 /openzfs#466 zio_nowait (zio=0x7f0350002fb0) at ../../module/zfs/zio.c:1456 /openzfs#467 0x00007f03c805ed43 in vdev_mirror_io_done (zio=0x7f033957ebf0) at ../../module/zfs/vdev_mirror.c:499 /openzfs#468 0x00007f03c807a0c0 in zio_vdev_io_done (zio=0x7f033957ebf0) at ../../module/zfs/zio.c:2707 /openzfs#469 0x00007f03c808285b in __zio_execute (zio=0x7f033957ebf0) at ../../module/zfs/zio.c:1399 /openzfs#470 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f0390001330, pio=0x7f033957ebf0) at ../../module/zfs/zio.c:547 /openzfs#471 zio_done (zio=0x7f0390001330) at ../../module/zfs/zio.c:3278 /openzfs#472 0x00007f03c808285b in __zio_execute (zio=0x7f0390001330) at ../../module/zfs/zio.c:1399 /openzfs#473 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4013a00, pio=0x7f0390001330) at ../../module/zfs/zio.c:547 /openzfs#474 zio_done (zio=0x7f03b4013a00) at ../../module/zfs/zio.c:3278 /openzfs#475 0x00007f03c808285b in __zio_execute (zio=0x7f03b4013a00) at ../../module/zfs/zio.c:1399 /openzfs#476 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4014210, pio=0x7f03b4013a00) at ../../module/zfs/zio.c:547 /openzfs#477 zio_done (zio=0x7f03b4014210) at ../../module/zfs/zio.c:3278 /openzfs#478 0x00007f03c808285b in __zio_execute (zio=0x7f03b4014210) at ../../module/zfs/zio.c:1399 /openzfs#479 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4014620, pio=0x7f03b4014210) at ../../module/zfs/zio.c:547 /openzfs#480 zio_done (zio=0x7f03b4014620) at ../../module/zfs/zio.c:3278 /openzfs#481 0x00007f03c807a6d3 in __zio_execute (zio=0x7f03b4014620) at ../../module/zfs/zio.c:1399 /openzfs#482 zio_execute (zio=zio@entry=0x7f03b4014620) at ../../module/zfs/zio.c:1337 /openzfs#483 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#484 0x00007f03c806106e in vdev_queue_io (zio=zio@entry=0x7f0350002be0) at ../../module/zfs/vdev_queue.c:747 /openzfs#485 0x00007f03c80818c1 in zio_vdev_io_start (zio=0x7f0350002be0) at ../../module/zfs/zio.c:2659 /openzfs#486 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002be0) at ../../module/zfs/zio.c:1399 /openzfs#487 zio_nowait (zio=0x7f0350002be0) at ../../module/zfs/zio.c:1456 /openzfs#488 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350002810) at ../../module/zfs/vdev_mirror.c:374 /openzfs#489 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002810) at ../../module/zfs/zio.c:1399 /openzfs#490 zio_nowait (zio=0x7f0350002810) at ../../module/zfs/zio.c:1456 /openzfs#491 0x00007f03c8064593 in vdev_raidz_io_start (zio=0x7f0350001270) at ../../module/zfs/vdev_raidz.c:1591 /openzfs#492 0x00007f03c807f243 in __zio_execute (zio=0x7f0350001270) at ../../module/zfs/zio.c:1399 /openzfs#493 zio_nowait (zio=0x7f0350001270) at ../../module/zfs/zio.c:1456 /openzfs#494 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350001e60) at ../../module/zfs/vdev_mirror.c:374 /openzfs#495 0x00007f03c807f243 in __zio_execute (zio=0x7f0350001e60) at ../../module/zfs/zio.c:1399 /openzfs#496 zio_nowait (zio=0x7f0350001e60) at ../../module/zfs/zio.c:1456 /openzfs#497 0x00007f03c805ed43 in vdev_mirror_io_done (zio=0x7f033a0c39c0) at ../../module/zfs/vdev_mirror.c:499 /openzfs#498 0x00007f03c807a0c0 in zio_vdev_io_done (zio=0x7f033a0c39c0) at ../../module/zfs/zio.c:2707 /openzfs#499 0x00007f03c808285b in __zio_execute (zio=0x7f033a0c39c0) at ../../module/zfs/zio.c:1399 /openzfs#500 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03a8003c00, pio=0x7f033a0c39c0) at ../../module/zfs/zio.c:547 /openzfs#501 zio_done (zio=0x7f03a8003c00) at ../../module/zfs/zio.c:3278 /openzfs#502 0x00007f03c808285b in __zio_execute (zio=0x7f03a8003c00) at ../../module/zfs/zio.c:1399 /openzfs#503 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800c400, pio=0x7f03a8003c00) at ../../module/zfs/zio.c:547 /openzfs#504 zio_done (zio=0x7f038800c400) at ../../module/zfs/zio.c:3278 /openzfs#505 0x00007f03c808285b in __zio_execute (zio=0x7f038800c400) at ../../module/zfs/zio.c:1399 /openzfs#506 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800da00, pio=0x7f038800c400) at ../../module/zfs/zio.c:547 /openzfs#507 zio_done (zio=0x7f038800da00) at ../../module/zfs/zio.c:3278 /openzfs#508 0x00007f03c808285b in __zio_execute (zio=0x7f038800da00) at ../../module/zfs/zio.c:1399 /openzfs#509 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800fd80, pio=0x7f038800da00) at ../../module/zfs/zio.c:547 /openzfs#510 zio_done (zio=0x7f038800fd80) at ../../module/zfs/zio.c:3278 /openzfs#511 0x00007f03c807a6d3 in __zio_execute (zio=0x7f038800fd80) at ../../module/zfs/zio.c:1399 /openzfs#512 zio_execute (zio=zio@entry=0x7f038800fd80) at ../../module/zfs/zio.c:1337 /openzfs#513 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#514 0x00007f03c806119d in vdev_queue_io_done (zio=zio@entry=0x7f03a0010950) at ../../module/zfs/vdev_queue.c:775 /openzfs#515 0x00007f03c807a0e8 in zio_vdev_io_done (zio=0x7f03a0010950) at ../../module/zfs/zio.c:2686 /openzfs#516 0x00007f03c807a6d3 in __zio_execute (zio=0x7f03a0010950) at ../../module/zfs/zio.c:1399 /openzfs#517 zio_execute (zio=0x7f03a0010950) at ../../module/zfs/zio.c:1337 /openzfs#518 0x00007f03c7fcd0c4 in taskq_thread (arg=0x966d50) at ../../lib/libzpool/taskq.c:215 /openzfs#519 0x00007f03c7fc7937 in zk_thread_helper (arg=0x967e90) at ../../lib/libzpool/kernel.c:135 /openzfs#520 0x00007f03c78890a3 in start_thread (arg=0x7f03c2703700) at pthread_create.c:309 /openzfs#521 0x00007f03c75c50fd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111 The backtrace was an infinite loop of `vdev_queue_io_to_issue()` invoking `zio_execute()` until it overran the stack. vdev_queue_io_to_issue() will ony invoke `zio_execute()` on raidz vdevs when aggregation I/Os are generated to improve aggregation continuity. These I/Os do not trigger any writes. However, it appears that they can be generated in such a way that they recurse infinitely upon return to `vdev_queue_io_to_issue()`. As a consequence, we see the number of parents by 1 each time the recursion returns to `vdev_raidz_io_start()`. Signed-off-by: Richard Yao <ryao@gentoo.org>

The below excerpt of a backtrace is from a ztest failure when running ZoL's ztest. /openzfs#453 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#454 0x00007f03c806106e in vdev_queue_io (zio=zio@entry=0x7f0350003de0) at ../../module/zfs/vdev_queue.c:747 /openzfs#455 0x00007f03c80818c1 in zio_vdev_io_start (zio=0x7f0350003de0) at ../../module/zfs/zio.c:2659 /openzfs#456 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003de0) at ../../module/zfs/zio.c:1399 /openzfs#457 zio_nowait (zio=0x7f0350003de0) at ../../module/zfs/zio.c:1456 /openzfs#458 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350003a10) at ../../module/zfs/vdev_mirror.c:374 /openzfs#459 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003a10) at ../../module/zfs/zio.c:1399 /openzfs#460 zio_nowait (zio=0x7f0350003a10) at ../../module/zfs/zio.c:1456 /openzfs#461 0x00007f03c806464c in vdev_raidz_io_start (zio=0x7f0350003380) at ../../module/zfs/vdev_raidz.c:1607 /openzfs#462 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003380) at ../../module/zfs/zio.c:1399 /openzfs#463 zio_nowait (zio=0x7f0350003380) at ../../module/zfs/zio.c:1456 /openzfs#464 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350002fb0) at ../../module/zfs/vdev_mirror.c:374 /openzfs#465 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002fb0) at ../../module/zfs/zio.c:1399 /openzfs#466 zio_nowait (zio=0x7f0350002fb0) at ../../module/zfs/zio.c:1456 /openzfs#467 0x00007f03c805ed43 in vdev_mirror_io_done (zio=0x7f033957ebf0) at ../../module/zfs/vdev_mirror.c:499 /openzfs#468 0x00007f03c807a0c0 in zio_vdev_io_done (zio=0x7f033957ebf0) at ../../module/zfs/zio.c:2707 /openzfs#469 0x00007f03c808285b in __zio_execute (zio=0x7f033957ebf0) at ../../module/zfs/zio.c:1399 /openzfs#470 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f0390001330, pio=0x7f033957ebf0) at ../../module/zfs/zio.c:547 /openzfs#471 zio_done (zio=0x7f0390001330) at ../../module/zfs/zio.c:3278 /openzfs#472 0x00007f03c808285b in __zio_execute (zio=0x7f0390001330) at ../../module/zfs/zio.c:1399 /openzfs#473 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4013a00, pio=0x7f0390001330) at ../../module/zfs/zio.c:547 /openzfs#474 zio_done (zio=0x7f03b4013a00) at ../../module/zfs/zio.c:3278 /openzfs#475 0x00007f03c808285b in __zio_execute (zio=0x7f03b4013a00) at ../../module/zfs/zio.c:1399 /openzfs#476 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4014210, pio=0x7f03b4013a00) at ../../module/zfs/zio.c:547 /openzfs#477 zio_done (zio=0x7f03b4014210) at ../../module/zfs/zio.c:3278 /openzfs#478 0x00007f03c808285b in __zio_execute (zio=0x7f03b4014210) at ../../module/zfs/zio.c:1399 /openzfs#479 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4014620, pio=0x7f03b4014210) at ../../module/zfs/zio.c:547 /openzfs#480 zio_done (zio=0x7f03b4014620) at ../../module/zfs/zio.c:3278 /openzfs#481 0x00007f03c807a6d3 in __zio_execute (zio=0x7f03b4014620) at ../../module/zfs/zio.c:1399 /openzfs#482 zio_execute (zio=zio@entry=0x7f03b4014620) at ../../module/zfs/zio.c:1337 /openzfs#483 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#484 0x00007f03c806106e in vdev_queue_io (zio=zio@entry=0x7f0350002be0) at ../../module/zfs/vdev_queue.c:747 /openzfs#485 0x00007f03c80818c1 in zio_vdev_io_start (zio=0x7f0350002be0) at ../../module/zfs/zio.c:2659 /openzfs#486 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002be0) at ../../module/zfs/zio.c:1399 /openzfs#487 zio_nowait (zio=0x7f0350002be0) at ../../module/zfs/zio.c:1456 /openzfs#488 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350002810) at ../../module/zfs/vdev_mirror.c:374 /openzfs#489 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002810) at ../../module/zfs/zio.c:1399 /openzfs#490 zio_nowait (zio=0x7f0350002810) at ../../module/zfs/zio.c:1456 /openzfs#491 0x00007f03c8064593 in vdev_raidz_io_start (zio=0x7f0350001270) at ../../module/zfs/vdev_raidz.c:1591 /openzfs#492 0x00007f03c807f243 in __zio_execute (zio=0x7f0350001270) at ../../module/zfs/zio.c:1399 /openzfs#493 zio_nowait (zio=0x7f0350001270) at ../../module/zfs/zio.c:1456 /openzfs#494 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350001e60) at ../../module/zfs/vdev_mirror.c:374 /openzfs#495 0x00007f03c807f243 in __zio_execute (zio=0x7f0350001e60) at ../../module/zfs/zio.c:1399 /openzfs#496 zio_nowait (zio=0x7f0350001e60) at ../../module/zfs/zio.c:1456 /openzfs#497 0x00007f03c805ed43 in vdev_mirror_io_done (zio=0x7f033a0c39c0) at ../../module/zfs/vdev_mirror.c:499 /openzfs#498 0x00007f03c807a0c0 in zio_vdev_io_done (zio=0x7f033a0c39c0) at ../../module/zfs/zio.c:2707 /openzfs#499 0x00007f03c808285b in __zio_execute (zio=0x7f033a0c39c0) at ../../module/zfs/zio.c:1399 /openzfs#500 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03a8003c00, pio=0x7f033a0c39c0) at ../../module/zfs/zio.c:547 /openzfs#501 zio_done (zio=0x7f03a8003c00) at ../../module/zfs/zio.c:3278 /openzfs#502 0x00007f03c808285b in __zio_execute (zio=0x7f03a8003c00) at ../../module/zfs/zio.c:1399 /openzfs#503 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800c400, pio=0x7f03a8003c00) at ../../module/zfs/zio.c:547 /openzfs#504 zio_done (zio=0x7f038800c400) at ../../module/zfs/zio.c:3278 /openzfs#505 0x00007f03c808285b in __zio_execute (zio=0x7f038800c400) at ../../module/zfs/zio.c:1399 /openzfs#506 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800da00, pio=0x7f038800c400) at ../../module/zfs/zio.c:547 /openzfs#507 zio_done (zio=0x7f038800da00) at ../../module/zfs/zio.c:3278 /openzfs#508 0x00007f03c808285b in __zio_execute (zio=0x7f038800da00) at ../../module/zfs/zio.c:1399 /openzfs#509 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800fd80, pio=0x7f038800da00) at ../../module/zfs/zio.c:547 /openzfs#510 zio_done (zio=0x7f038800fd80) at ../../module/zfs/zio.c:3278 /openzfs#511 0x00007f03c807a6d3 in __zio_execute (zio=0x7f038800fd80) at ../../module/zfs/zio.c:1399 /openzfs#512 zio_execute (zio=zio@entry=0x7f038800fd80) at ../../module/zfs/zio.c:1337 /openzfs#513 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#514 0x00007f03c806119d in vdev_queue_io_done (zio=zio@entry=0x7f03a0010950) at ../../module/zfs/vdev_queue.c:775 /openzfs#515 0x00007f03c807a0e8 in zio_vdev_io_done (zio=0x7f03a0010950) at ../../module/zfs/zio.c:2686 /openzfs#516 0x00007f03c807a6d3 in __zio_execute (zio=0x7f03a0010950) at ../../module/zfs/zio.c:1399 /openzfs#517 zio_execute (zio=0x7f03a0010950) at ../../module/zfs/zio.c:1337 /openzfs#518 0x00007f03c7fcd0c4 in taskq_thread (arg=0x966d50) at ../../lib/libzpool/taskq.c:215 /openzfs#519 0x00007f03c7fc7937 in zk_thread_helper (arg=0x967e90) at ../../lib/libzpool/kernel.c:135 /openzfs#520 0x00007f03c78890a3 in start_thread (arg=0x7f03c2703700) at pthread_create.c:309 /openzfs#521 0x00007f03c75c50fd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111 The backtrace was an infinite loop of `vdev_queue_io_to_issue()` invoking `zio_execute()` until it overran the stack. vdev_queue_io_to_issue() will ony invoke `zio_execute()` on raidz vdevs when aggregation I/Os are generated to improve aggregation continuity. These I/Os do not trigger any writes. However, it appears that they can be generated in such a way that they recurse infinitely upon return to `vdev_queue_io_to_issue()`. As a consequence, we see the number of parents by 1 each time the recursion returns to `vdev_raidz_io_start()`. Signed-off-by: Richard Yao <richard.yao@clusterhq.com>

The below excerpt of a backtrace is from a ztest failure when running ZoL's ztest. /openzfs#453 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#454 0x00007f03c806106e in vdev_queue_io (zio=zio@entry=0x7f0350003de0) at ../../module/zfs/vdev_queue.c:747 /openzfs#455 0x00007f03c80818c1 in zio_vdev_io_start (zio=0x7f0350003de0) at ../../module/zfs/zio.c:2659 /openzfs#456 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003de0) at ../../module/zfs/zio.c:1399 /openzfs#457 zio_nowait (zio=0x7f0350003de0) at ../../module/zfs/zio.c:1456 /openzfs#458 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350003a10) at ../../module/zfs/vdev_mirror.c:374 /openzfs#459 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003a10) at ../../module/zfs/zio.c:1399 /openzfs#460 zio_nowait (zio=0x7f0350003a10) at ../../module/zfs/zio.c:1456 /openzfs#461 0x00007f03c806464c in vdev_raidz_io_start (zio=0x7f0350003380) at ../../module/zfs/vdev_raidz.c:1607 /openzfs#462 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003380) at ../../module/zfs/zio.c:1399 /openzfs#463 zio_nowait (zio=0x7f0350003380) at ../../module/zfs/zio.c:1456 /openzfs#464 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350002fb0) at ../../module/zfs/vdev_mirror.c:374 /openzfs#465 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002fb0) at ../../module/zfs/zio.c:1399 /openzfs#466 zio_nowait (zio=0x7f0350002fb0) at ../../module/zfs/zio.c:1456 /openzfs#467 0x00007f03c805ed43 in vdev_mirror_io_done (zio=0x7f033957ebf0) at ../../module/zfs/vdev_mirror.c:499 /openzfs#468 0x00007f03c807a0c0 in zio_vdev_io_done (zio=0x7f033957ebf0) at ../../module/zfs/zio.c:2707 /openzfs#469 0x00007f03c808285b in __zio_execute (zio=0x7f033957ebf0) at ../../module/zfs/zio.c:1399 /openzfs#470 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f0390001330, pio=0x7f033957ebf0) at ../../module/zfs/zio.c:547 /openzfs#471 zio_done (zio=0x7f0390001330) at ../../module/zfs/zio.c:3278 /openzfs#472 0x00007f03c808285b in __zio_execute (zio=0x7f0390001330) at ../../module/zfs/zio.c:1399 /openzfs#473 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4013a00, pio=0x7f0390001330) at ../../module/zfs/zio.c:547 /openzfs#474 zio_done (zio=0x7f03b4013a00) at ../../module/zfs/zio.c:3278 /openzfs#475 0x00007f03c808285b in __zio_execute (zio=0x7f03b4013a00) at ../../module/zfs/zio.c:1399 /openzfs#476 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4014210, pio=0x7f03b4013a00) at ../../module/zfs/zio.c:547 /openzfs#477 zio_done (zio=0x7f03b4014210) at ../../module/zfs/zio.c:3278 /openzfs#478 0x00007f03c808285b in __zio_execute (zio=0x7f03b4014210) at ../../module/zfs/zio.c:1399 /openzfs#479 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4014620, pio=0x7f03b4014210) at ../../module/zfs/zio.c:547 /openzfs#480 zio_done (zio=0x7f03b4014620) at ../../module/zfs/zio.c:3278 /openzfs#481 0x00007f03c807a6d3 in __zio_execute (zio=0x7f03b4014620) at ../../module/zfs/zio.c:1399 /openzfs#482 zio_execute (zio=zio@entry=0x7f03b4014620) at ../../module/zfs/zio.c:1337 /openzfs#483 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#484 0x00007f03c806106e in vdev_queue_io (zio=zio@entry=0x7f0350002be0) at ../../module/zfs/vdev_queue.c:747 /openzfs#485 0x00007f03c80818c1 in zio_vdev_io_start (zio=0x7f0350002be0) at ../../module/zfs/zio.c:2659 /openzfs#486 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002be0) at ../../module/zfs/zio.c:1399 /openzfs#487 zio_nowait (zio=0x7f0350002be0) at ../../module/zfs/zio.c:1456 /openzfs#488 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350002810) at ../../module/zfs/vdev_mirror.c:374 /openzfs#489 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002810) at ../../module/zfs/zio.c:1399 /openzfs#490 zio_nowait (zio=0x7f0350002810) at ../../module/zfs/zio.c:1456 /openzfs#491 0x00007f03c8064593 in vdev_raidz_io_start (zio=0x7f0350001270) at ../../module/zfs/vdev_raidz.c:1591 /openzfs#492 0x00007f03c807f243 in __zio_execute (zio=0x7f0350001270) at ../../module/zfs/zio.c:1399 /openzfs#493 zio_nowait (zio=0x7f0350001270) at ../../module/zfs/zio.c:1456 /openzfs#494 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350001e60) at ../../module/zfs/vdev_mirror.c:374 /openzfs#495 0x00007f03c807f243 in __zio_execute (zio=0x7f0350001e60) at ../../module/zfs/zio.c:1399 /openzfs#496 zio_nowait (zio=0x7f0350001e60) at ../../module/zfs/zio.c:1456 /openzfs#497 0x00007f03c805ed43 in vdev_mirror_io_done (zio=0x7f033a0c39c0) at ../../module/zfs/vdev_mirror.c:499 /openzfs#498 0x00007f03c807a0c0 in zio_vdev_io_done (zio=0x7f033a0c39c0) at ../../module/zfs/zio.c:2707 /openzfs#499 0x00007f03c808285b in __zio_execute (zio=0x7f033a0c39c0) at ../../module/zfs/zio.c:1399 /openzfs#500 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03a8003c00, pio=0x7f033a0c39c0) at ../../module/zfs/zio.c:547 /openzfs#501 zio_done (zio=0x7f03a8003c00) at ../../module/zfs/zio.c:3278 /openzfs#502 0x00007f03c808285b in __zio_execute (zio=0x7f03a8003c00) at ../../module/zfs/zio.c:1399 /openzfs#503 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800c400, pio=0x7f03a8003c00) at ../../module/zfs/zio.c:547 /openzfs#504 zio_done (zio=0x7f038800c400) at ../../module/zfs/zio.c:3278 /openzfs#505 0x00007f03c808285b in __zio_execute (zio=0x7f038800c400) at ../../module/zfs/zio.c:1399 /openzfs#506 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800da00, pio=0x7f038800c400) at ../../module/zfs/zio.c:547 /openzfs#507 zio_done (zio=0x7f038800da00) at ../../module/zfs/zio.c:3278 /openzfs#508 0x00007f03c808285b in __zio_execute (zio=0x7f038800da00) at ../../module/zfs/zio.c:1399 /openzfs#509 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800fd80, pio=0x7f038800da00) at ../../module/zfs/zio.c:547 /openzfs#510 zio_done (zio=0x7f038800fd80) at ../../module/zfs/zio.c:3278 /openzfs#511 0x00007f03c807a6d3 in __zio_execute (zio=0x7f038800fd80) at ../../module/zfs/zio.c:1399 /openzfs#512 zio_execute (zio=zio@entry=0x7f038800fd80) at ../../module/zfs/zio.c:1337 /openzfs#513 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#514 0x00007f03c806119d in vdev_queue_io_done (zio=zio@entry=0x7f03a0010950) at ../../module/zfs/vdev_queue.c:775 /openzfs#515 0x00007f03c807a0e8 in zio_vdev_io_done (zio=0x7f03a0010950) at ../../module/zfs/zio.c:2686 /openzfs#516 0x00007f03c807a6d3 in __zio_execute (zio=0x7f03a0010950) at ../../module/zfs/zio.c:1399 /openzfs#517 zio_execute (zio=0x7f03a0010950) at ../../module/zfs/zio.c:1337 /openzfs#518 0x00007f03c7fcd0c4 in taskq_thread (arg=0x966d50) at ../../lib/libzpool/taskq.c:215 /openzfs#519 0x00007f03c7fc7937 in zk_thread_helper (arg=0x967e90) at ../../lib/libzpool/kernel.c:135 /openzfs#520 0x00007f03c78890a3 in start_thread (arg=0x7f03c2703700) at pthread_create.c:309 /openzfs#521 0x00007f03c75c50fd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111 The backtrace was an infinite loop of `vdev_queue_io_to_issue()` invoking `zio_execute()` until it overran the stack. vdev_queue_io_to_issue() will ony invoke `zio_execute()` on raidz vdevs when aggregation I/Os are generated to improve aggregation continuity. These I/Os do not trigger any writes. However, it appears that they can be generated in such a way that they recurse infinitely upon return to `vdev_queue_io_to_issue()`. Signed-off-by: Richard Yao <richard.yao@clusterhq.com>

The below excerpt of a backtrace is from a ztest failure when running ZoL's ztest: /openzfs#453 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#454 0x00007f03c806106e in vdev_queue_io (zio=zio@entry=0x7f0350003de0) at ../../module/zfs/vdev_queue.c:747 /openzfs#455 0x00007f03c80818c1 in zio_vdev_io_start (zio=0x7f0350003de0) at ../../module/zfs/zio.c:2659 /openzfs#456 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003de0) at ../../module/zfs/zio.c:1399 /openzfs#457 zio_nowait (zio=0x7f0350003de0) at ../../module/zfs/zio.c:1456 /openzfs#458 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350003a10) at ../../module/zfs/vdev_mirror.c:374 /openzfs#459 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003a10) at ../../module/zfs/zio.c:1399 /openzfs#460 zio_nowait (zio=0x7f0350003a10) at ../../module/zfs/zio.c:1456 /openzfs#461 0x00007f03c806464c in vdev_raidz_io_start (zio=0x7f0350003380) at ../../module/zfs/vdev_raidz.c:1607 /openzfs#462 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003380) at ../../module/zfs/zio.c:1399 /openzfs#463 zio_nowait (zio=0x7f0350003380) at ../../module/zfs/zio.c:1456 /openzfs#464 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350002fb0) at ../../module/zfs/vdev_mirror.c:374 /openzfs#465 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002fb0) at ../../module/zfs/zio.c:1399 /openzfs#466 zio_nowait (zio=0x7f0350002fb0) at ../../module/zfs/zio.c:1456 /openzfs#467 0x00007f03c805ed43 in vdev_mirror_io_done (zio=0x7f033957ebf0) at ../../module/zfs/vdev_mirror.c:499 /openzfs#468 0x00007f03c807a0c0 in zio_vdev_io_done (zio=0x7f033957ebf0) at ../../module/zfs/zio.c:2707 /openzfs#469 0x00007f03c808285b in __zio_execute (zio=0x7f033957ebf0) at ../../module/zfs/zio.c:1399 /openzfs#470 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f0390001330, pio=0x7f033957ebf0) at ../../module/zfs/zio.c:547 /openzfs#471 zio_done (zio=0x7f0390001330) at ../../module/zfs/zio.c:3278 /openzfs#472 0x00007f03c808285b in __zio_execute (zio=0x7f0390001330) at ../../module/zfs/zio.c:1399 /openzfs#473 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4013a00, pio=0x7f0390001330) at ../../module/zfs/zio.c:547 /openzfs#474 zio_done (zio=0x7f03b4013a00) at ../../module/zfs/zio.c:3278 /openzfs#475 0x00007f03c808285b in __zio_execute (zio=0x7f03b4013a00) at ../../module/zfs/zio.c:1399 /openzfs#476 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4014210, pio=0x7f03b4013a00) at ../../module/zfs/zio.c:547 /openzfs#477 zio_done (zio=0x7f03b4014210) at ../../module/zfs/zio.c:3278 /openzfs#478 0x00007f03c808285b in __zio_execute (zio=0x7f03b4014210) at ../../module/zfs/zio.c:1399 /openzfs#479 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4014620, pio=0x7f03b4014210) at ../../module/zfs/zio.c:547 /openzfs#480 zio_done (zio=0x7f03b4014620) at ../../module/zfs/zio.c:3278 /openzfs#481 0x00007f03c807a6d3 in __zio_execute (zio=0x7f03b4014620) at ../../module/zfs/zio.c:1399 /openzfs#482 zio_execute (zio=zio@entry=0x7f03b4014620) at ../../module/zfs/zio.c:1337 /openzfs#483 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#484 0x00007f03c806106e in vdev_queue_io (zio=zio@entry=0x7f0350002be0) at ../../module/zfs/vdev_queue.c:747 /openzfs#485 0x00007f03c80818c1 in zio_vdev_io_start (zio=0x7f0350002be0) at ../../module/zfs/zio.c:2659 /openzfs#486 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002be0) at ../../module/zfs/zio.c:1399 /openzfs#487 zio_nowait (zio=0x7f0350002be0) at ../../module/zfs/zio.c:1456 /openzfs#488 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350002810) at ../../module/zfs/vdev_mirror.c:374 /openzfs#489 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002810) at ../../module/zfs/zio.c:1399 /openzfs#490 zio_nowait (zio=0x7f0350002810) at ../../module/zfs/zio.c:1456 /openzfs#491 0x00007f03c8064593 in vdev_raidz_io_start (zio=0x7f0350001270) at ../../module/zfs/vdev_raidz.c:1591 /openzfs#492 0x00007f03c807f243 in __zio_execute (zio=0x7f0350001270) at ../../module/zfs/zio.c:1399 /openzfs#493 zio_nowait (zio=0x7f0350001270) at ../../module/zfs/zio.c:1456 /openzfs#494 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350001e60) at ../../module/zfs/vdev_mirror.c:374 /openzfs#495 0x00007f03c807f243 in __zio_execute (zio=0x7f0350001e60) at ../../module/zfs/zio.c:1399 /openzfs#496 zio_nowait (zio=0x7f0350001e60) at ../../module/zfs/zio.c:1456 /openzfs#497 0x00007f03c805ed43 in vdev_mirror_io_done (zio=0x7f033a0c39c0) at ../../module/zfs/vdev_mirror.c:499 /openzfs#498 0x00007f03c807a0c0 in zio_vdev_io_done (zio=0x7f033a0c39c0) at ../../module/zfs/zio.c:2707 /openzfs#499 0x00007f03c808285b in __zio_execute (zio=0x7f033a0c39c0) at ../../module/zfs/zio.c:1399 /openzfs#500 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03a8003c00, pio=0x7f033a0c39c0) at ../../module/zfs/zio.c:547 /openzfs#501 zio_done (zio=0x7f03a8003c00) at ../../module/zfs/zio.c:3278 /openzfs#502 0x00007f03c808285b in __zio_execute (zio=0x7f03a8003c00) at ../../module/zfs/zio.c:1399 /openzfs#503 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800c400, pio=0x7f03a8003c00) at ../../module/zfs/zio.c:547 /openzfs#504 zio_done (zio=0x7f038800c400) at ../../module/zfs/zio.c:3278 /openzfs#505 0x00007f03c808285b in __zio_execute (zio=0x7f038800c400) at ../../module/zfs/zio.c:1399 /openzfs#506 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800da00, pio=0x7f038800c400) at ../../module/zfs/zio.c:547 /openzfs#507 zio_done (zio=0x7f038800da00) at ../../module/zfs/zio.c:3278 /openzfs#508 0x00007f03c808285b in __zio_execute (zio=0x7f038800da00) at ../../module/zfs/zio.c:1399 /openzfs#509 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800fd80, pio=0x7f038800da00) at ../../module/zfs/zio.c:547 /openzfs#510 zio_done (zio=0x7f038800fd80) at ../../module/zfs/zio.c:3278 /openzfs#511 0x00007f03c807a6d3 in __zio_execute (zio=0x7f038800fd80) at ../../module/zfs/zio.c:1399 /openzfs#512 zio_execute (zio=zio@entry=0x7f038800fd80) at ../../module/zfs/zio.c:1337 /openzfs#513 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#514 0x00007f03c806119d in vdev_queue_io_done (zio=zio@entry=0x7f03a0010950) at ../../module/zfs/vdev_queue.c:775 /openzfs#515 0x00007f03c807a0e8 in zio_vdev_io_done (zio=0x7f03a0010950) at ../../module/zfs/zio.c:2686 /openzfs#516 0x00007f03c807a6d3 in __zio_execute (zio=0x7f03a0010950) at ../../module/zfs/zio.c:1399 /openzfs#517 zio_execute (zio=0x7f03a0010950) at ../../module/zfs/zio.c:1337 /openzfs#518 0x00007f03c7fcd0c4 in taskq_thread (arg=0x966d50) at ../../lib/libzpool/taskq.c:215 /openzfs#519 0x00007f03c7fc7937 in zk_thread_helper (arg=0x967e90) at ../../lib/libzpool/kernel.c:135 /openzfs#520 0x00007f03c78890a3 in start_thread (arg=0x7f03c2703700) at pthread_create.c:309 /openzfs#521 0x00007f03c75c50fd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111 This occurred when ztest was simulating a scrub under heavy I/O load. Under those circumstances, it was possible for a mix of noop I/Os for aggregation continuity and the I/O elevator to generate arbitrarily deep recursion. This patch modifies ZFS to propapage a recursion counter inside the zio_t objects such that IOs will be redispatched upon reaching a given recursion depth. We can detect long call chains and dispatch to another ZIO taskq. We cut in-line when we do this to minimize the potential for taskq exhaustion that can prevent a zio from notifying its parent. Signed-off-by: Richard Yao <ryao@gentoo.org>

The flags argument in spin_lock_irqsave is modified out side of spin_lock context. We cannot use a shared variable like tq->tq_lock_flags for them. This patch removes it and uses local variable for the flags. Signed-off-by: Chunwei Chen <david.chen@osnexus.com> Signed-off-by: Brian Behlendorf <behlendorf1@llnl.gov> Closes openzfs#506

Introduce new claim() functions to claim space with the ExtentAllocator when opening a cache, instead of doing it as a side effect of open(). Use the "builder" pattern to initialize the ExtentAllocator from a consistent state, ensuring that we don't try to claim after we start allocating. Add a heruistic check for leaked ExtentAllocator space. Code cleanup; no functional change.

…aster Merge remote-tracking branch '6.0/stage' into 'master'

behlendorf closed this as completed Mar 16, 2012

ryao mentioned this issue Oct 9, 2014

vdev_raidz_io_start: Ignore empty writes #2778

Closed

ryao mentioned this issue Oct 10, 2014

Redispatch ZIOs in deep call graphs #2786

Closed

pcd1193182 pushed a commit to pcd1193182/zfs that referenced this issue Sep 26, 2023

Merge pull request openzfs#506 from delphix/projects/merge-upstream/m…

2c0a87a

…aster Merge remote-tracking branch '6.0/stage' into 'master'

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Bug while moving files in pool via AFP #506

Bug while moving files in pool via AFP #506

uclageek commented Dec 26, 2011

behlendorf commented Jan 19, 2012

behlendorf commented Mar 16, 2012

Bug while moving files in pool via AFP #506

Bug while moving files in pool via AFP #506

Comments

uclageek commented Dec 26, 2011

behlendorf commented Jan 19, 2012

behlendorf commented Mar 16, 2012