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

ZFS have silently corrupted the meta data #1848

Closed
FransUrbo opened this issue Nov 9, 2013 · 12 comments
Closed

ZFS have silently corrupted the meta data #1848

FransUrbo opened this issue Nov 9, 2013 · 12 comments
Milestone

Comments

@FransUrbo
Copy link
Contributor

I had to reboot after about three month of uptime, so I'm not exactly sure what's changed... There where no (!!) indications that there was anything wrong with either the pool or any of the filesystems before the reboot.

But now I can't load the module.

If I first loads the spl module and then manually tries to load the zfs module, I get:

[  110.677165] SPL: Loaded module v0.6.1-1.20130514.crypto.mine
[  113.759816] zunicode: module license 'CDDL' taints kernel.
[  113.759819] Disabling lock debugging due to kernel taint
[  115.737512] SPL: using hostid 0xa8c00845
[  116.720730] general protection fault: 0000 [#1] SMP 
[  116.720894] Modules linked in: zfs(PO+) zcommon(PO) znvpair(PO) zavl(PO) zunicode(PO) spl(O) zlib_deflate binfmt_misc st appletalk psnap llc autofs4 crc32c nfsd nfs_acl auth_rpcgss nfs fscache lockd ib_iser rdma_cm ib_cm iw_cm ib_sa ib_mad ib_core ib_addr ipv6 iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi sunrpc dm_crypt nf_conntrack cpufreq_stats cpufreq_userspace it87 hwmon_vid i2c_dev loop eeepc_wmi asus_wmi sparse_keymap rfkill video pci_hotplug mxm_wmi evdev hid_generic snd_pcm_oss snd_mixer_oss freq_table mperf snd_pcm psmouse microcode kvm_amd serio_raw kvm snd_timer snd soundcore snd_page_alloc tpm_tis tpm tpm_bios k10temp i2c_piix4 i2c_core sp5100_tco pcspkr ehci_pci ehci_hcd processor button wmi ext3 jbd mbcache dm_mirror dm_region_hash dm_log dm_snapshot dm_mod sd_mod usb_storage usbhid hid firewire_ohci firewire_core crc_itu_t sata_mv r8169 mii ohci_hcd mvsas libsas scsi_transport_sas ahci libahci thermal fan thermal_sys nbd raid1 md_mod ide_gd_mod ide_core sata_sil libata scsi_mod
[  116.725724] CPU 1 
[  116.725770] Pid: 8845, comm: modprobe Tainted: P           O 3.9.0-rc6+tf.1 #1 To be filled by O.E.M. To be filled by O.E.M./SABERTOOTH 990FX
[  116.725959] RIP: 0010:[<ffffffffa097fcb7>]  [<ffffffffa097fcb7>] spl_kmem_cache_alloc+0x66/0xc9a [spl]
[  116.726117] RSP: 0000:ffff88040d1d14a8  EFLAGS: 00010246
[  116.726196] RAX: 00020074000014fd RBX: 00000000000ab400 RCX: 0000000000000004
[  116.726281] RDX: 0000000210000000 RSI: 0000000000000230 RDI: 000200740000141d
[  116.726366] RBP: ffff8803f377cb80 R08: 0000000021000000 R09: 00000000000ab400
[  116.726450] R10: 0000000210000000 R11: ffff8803f37bd358 R12: 000200740000141d
[  116.726535] R13: ffff8803f6636000 R14: ffffc90018acc000 R15: ffffffffa0a31c8c
[  116.726621] FS:  0000000000000000(0000) GS:ffff88041fc40000(0063) knlGS:00000000f75b56b0
[  116.726733] CS:  0010 DS: 002b ES: 002b CR0: 000000008005003b
[  116.726813] CR2: 00000000ffd21dd8 CR3: 000000040c18b000 CR4: 00000000000007e0
[  116.726899] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  116.726984] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[  116.727069] Process modprobe (pid: 8845, threadinfo ffff88040d1d0000, task ffff88040b79d800)
[  116.727182] Stack:
[  116.727251]  ffff8803f2e94c40 ffffffffa0ab3bfd 0000000000000000 0000000000000000
[  116.727510]  ffff8803f2e94c40 0000000000000202 0000000000000000 ffffffffa0ab7ba7
[  116.727765]  ffff8803f2dced80 0000000000000001 ffff8803f2dced80 0000000000000006
[  116.728022] Call Trace:
[  116.728138]  [<ffffffffa0ab3bfd>] ? zio_wait_for_children+0x4f/0x59 [zfs]
[  116.728256]  [<ffffffffa0ab7ba7>] ? zio_done+0x6e/0xdc7 [zfs]
[  116.728367]  [<ffffffffa0a31c8c>] ? dbuf_fill_done+0x61/0x61 [zfs]
[  116.728478]  [<ffffffffa0a2e736>] ? arc_get_data_buf+0x1a5/0x3bc [zfs]
[  116.728591]  [<ffffffffa0a2eaa6>] ? arc_buf_alloc+0xb0/0xdc [zfs]
[  116.728702]  [<ffffffffa0a2ed5b>] ? arc_read_nolock+0x26b/0x6af [zfs]
[  116.728787]  [<ffffffffa09838f1>] ? taskq_init_ent+0x3d/0x8b [spl]
[  116.728899]  [<ffffffffa0a2f6d0>] ? arc_read+0xc2/0x16a [zfs]
[  116.729012]  [<ffffffffa0ab7a82>] ? zio_null+0x5b/0x60 [zfs]
[  116.729123]  [<ffffffffa0a31c8c>] ? dbuf_fill_done+0x61/0x61 [zfs]
[  116.729235]  [<ffffffffa0a32632>] ? dbuf_read+0x407/0x64b [zfs]
[  116.729348]  [<ffffffffa0a48098>] ? dnode_hold_impl+0x213/0x45f [zfs]
[  116.729462]  [<ffffffffa0a382a3>] ? dmu_buf_hold+0x3f/0x17c [zfs]
[  116.729577]  [<ffffffffa0a89899>] ? zap_lockdir+0x58/0x67b [zfs]
[  116.729661]  [<ffffffff8105e557>] ? __init_waitqueue_head+0x17/0x28
[  116.729776]  [<ffffffffa0a3d149>] ? dmu_objset_open_impl+0x58f/0x5d6 [zfs]
[  116.729893]  [<ffffffffa0a8b30f>] ? zap_lookup_norm+0x3f/0x153 [zfs]
[  116.730009]  [<ffffffffa0a8b490>] ? zap_lookup+0x2a/0x32 [zfs]
[  116.730125]  [<ffffffffa0a6d203>] ? spa_load+0x7e4/0x1818 [zfs]
[  116.730239]  [<ffffffffa0a8bd25>] ? zcrypt_keystore_init+0x6c/0x8f [zfs]
[  116.730356]  [<ffffffffa0a6c34d>] ? spa_activate+0x35a/0x369 [zfs]
[  116.730472]  [<ffffffffa0a698b7>] ? spa_deactivate+0x1c4/0x20d [zfs]
[  116.730588]  [<ffffffffa0a6e39d>] ? spa_load_best+0x166/0x1fc [zfs]
[  116.730704]  [<ffffffffa0a6e8fc>] ? spa_open_common+0xf6/0x2d4 [zfs]
[  116.730821]  [<ffffffffa0a583a7>] ? dsl_dir_open_spa+0xea/0x593 [zfs]
[  116.730937]  [<ffffffffa0a9bdc8>] ? _init+0x111/0x111 [zfs]
[  116.731048]  [<ffffffffa0a3ad8d>] ? dmu_objset_find_spa+0x55/0x371 [zfs]
[  116.731164]  [<ffffffffa0abe868>] ? __zvol_create_minor+0x656/0x656 [zfs]
[  116.731250]  [<ffffffff81269888>] ? kobj_map+0x67/0x127
[  116.731331]  [<ffffffff81269935>] ? kobj_map+0x114/0x127
[  116.731443]  [<ffffffffa0abe0f9>] ? zvol_replay_write+0xa1/0xa1 [zfs]
[  116.731558]  [<ffffffffa0a9bdc8>] ? _init+0x111/0x111 [zfs]
[  116.731671]  [<ffffffffa0abf808>] ? zvol_create_minors+0x77/0xad [zfs]
[  116.731787]  [<ffffffffa0abf930>] ? zvol_init+0xf2/0xf6 [zfs]
[  116.731900]  [<ffffffffa0a9bccc>] ? _init+0x15/0x111 [zfs]
[  116.731981]  [<ffffffff81002079>] ? do_one_initcall+0x79/0x134
[  116.732063]  [<ffffffff81090666>] ? load_module+0x124a/0x14de
[  116.732144]  [<ffffffff8108e568>] ? free_notes_attrs+0x41/0x41
[  116.732226]  [<ffffffff81090aee>] ? sys_init_module+0xa9/0xad
[  116.732308]  [<ffffffff813591c9>] ? ia32_do_call+0x13/0x13
[  116.732387] Code: e7 98 a0 ba 01 00 00 00 be 00 08 00 00 31 ff 31 c0 48 c7 04 24 60 e8 98 a0 e8 61 c0 ff ff 49 8d 84 24 e0 00 00 00 48 89 44 24 70 <f0> 41 ff 84 24 e0 00 00 00 9c 58 66 66 90 66 90 48 89 44 24 68 
[  116.740162] RIP  [<ffffffffa097fcb7>] spl_kmem_cache_alloc+0x66/0xc9a [spl]
[  116.740285]  RSP <ffff88040d1d14a8>
[  116.740375] ---[ end trace 8991b88e6376ddf2 ]---

If I remove the cache device, I instead get a lzjb_decompress oops:

[ 1293.843904] SPL: Loaded module v0.6.2-1.20130824.crypto.mine
[ 1296.118178] zunicode: module license 'CDDL' taints kernel.
[ 1296.118181] Disabling lock debugging due to kernel taint
[ 1296.166694] ZFS: Loaded module v0.6.2-1.20130824.iscsi.crypto.mine, ZFS pool version 5000, ZFS filesystem version 5
[ 1416.223255] BUG: unable to handle kernel paging request at ffffc90016598000
[ 1416.223421] IP: [<ffffffffa08db2f2>] lzjb_decompress+0x2e/0x92 [zfs]
[ 1416.223558] PGD 41d821067 PUD 41d822067 PMD 3f43e8067 PTE 0
[ 1416.223784] Oops: 0000 [#1] SMP 
[ 1416.223928] Modules linked in: zfs(PO) zcommon(PO) znvpair(PO) zavl(PO) zunicode(PO) spl(O) zlib_deflate binfmt_misc st appletalk psnap llc autofs4 crc32c nfsd nfs_acl auth_rpcgss nfs fscache lockd ib_iser rdma_cm ib_cm iw_cm ib_sa ib_mad ib_core ib_addr ipv6 iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi sunrpc dm_crypt nf_conntrack cpufreq_stats cpufreq_userspace it87 hwmon_vid i2c_dev loop eeepc_wmi asus_wmi sparse_keymap rfkill video pci_hotplug mxm_wmi hid_generic evdev snd_pcm_oss snd_mixer_oss snd_pcm freq_table mperf microcode kvm_amd kvm snd_timer snd soundcore snd_page_alloc tpm_tis tpm tpm_bios k10temp i2c_piix4 i2c_core sp5100_tco pcspkr ehci_pci ehci_hcd button wmi processor ext3 jbd mbcache dm_mirror dm_region_hash dm_log dm_snapshot dm_mod sd_mod usb_storage usbhid hid firewire_ohci firewire_core crc_itu_t r8169 mii sata_mv mvsas libsas scsi_transport_sas ohci_hcd ahci libahci thermal fan thermal_sys nbd raid1 md_mod ide_gd_mod ide_core sata_sil libata scsi_mod
[ 1416.228642] CPU 5 
[ 1416.228688] Pid: 9163, comm: z_rd_int/5 Tainted: P           O 3.9.0-rc6+tf.1 #1 To be filled by O.E.M. To be filled by O.E.M./SABERTOOTH 990FX
[ 1416.228880] RIP: 0010:[<ffffffffa08db2f2>]  [<ffffffffa08db2f2>] lzjb_decompress+0x2e/0x92 [zfs]
[ 1416.229044] RSP: 0000:ffff8803f77fbc08  EFLAGS: 00010283
[ 1416.229123] RAX: 0000000000000000 RBX: ffffc90016453000 RCX: 0000000000000000
[ 1416.229208] RDX: 0000000000000003 RSI: ffffc9001644f000 RDI: ffffc90016598000
[ 1416.229292] RBP: ffff8803f4533e00 R08: ffffc90016452c0c R09: 0000000000000010
[ 1416.229377] R10: ffffc900164528ad R11: 0000000000000000 R12: 0000000000000000
[ 1416.229461] R13: ffff88040bdfc000 R14: 0000000000000000 R15: ffff8803f4533c60
[ 1416.229546] FS:  0000000000000000(0000) GS:ffff88041fd40000(0000) knlGS:00000000f6fe6b10
[ 1416.229658] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 1416.229738] CR2: ffffc90016598000 CR3: 000000040b189000 CR4: 00000000000007e0
[ 1416.229823] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 1416.229908] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[ 1416.229992] Process z_rd_int/5 (pid: 9163, threadinfo ffff8803f77fa000, task ffff88040d8cf040)
[ 1416.230106] Stack:
[ 1416.230173]  ffff8803f4533e00 ffffffffa092d1ab ffff88040dc99300 ffffffffa092c7e7
[ 1416.230429]  ffff8803f4533e00 0000000000100000 ffff8803f4533e00 ffffffffa09302b0
[ 1416.230685]  ffff8803f4533c60 ffffffffa07f7af0 ffff8803f4533e00 ffff8803f4533e00
[ 1416.230940] Call Trace:
[ 1416.231021]  [<ffffffffa092d1ab>] ? zio_decompress+0x36/0x46 [zfs]
[ 1416.231113]  [<ffffffffa092c7e7>] ? zio_pop_transforms+0x24/0x86 [zfs]
[ 1416.231206]  [<ffffffffa09302b0>] ? zio_done+0x194/0xab0 [zfs]
[ 1416.231289]  [<ffffffffa07f7af0>] ? kmem_free_debug+0xc5/0x10d [spl]
[ 1416.231382]  [<ffffffffa0930b43>] ? zio_done+0xa27/0xab0 [zfs]
[ 1416.231475]  [<ffffffffa08fc59c>] ? vdev_raidz_map_free+0x22/0x89 [zfs]
[ 1416.231568]  [<ffffffffa0930b43>] ? zio_done+0xa27/0xab0 [zfs]
[ 1416.231658]  [<ffffffffa092c591>] ? zio_wait_for_children+0x4f/0x59 [zfs]
[ 1416.231752]  [<ffffffffa092d8d3>] ? zio_execute+0xf2/0x118 [zfs]
[ 1416.231835]  [<ffffffffa07fb6fe>] ? taskq_thread+0x2d2/0x45c [spl]
[ 1416.231919]  [<ffffffff8106bba6>] ? try_to_wake_up+0x237/0x249
[ 1416.232000]  [<ffffffff8106bbb8>] ? try_to_wake_up+0x249/0x249
[ 1416.232083]  [<ffffffffa07fb42c>] ? task_expire+0x104/0x104 [spl]
[ 1416.232166]  [<ffffffff8105dcbd>] ? kthread+0xb0/0xba
[ 1416.232245]  [<ffffffff8105dc0d>] ? __init_kthread_worker+0x2d/0x2d
[ 1416.232328]  [<ffffffff813576bc>] ? ret_from_fork+0x7c/0xb0
[ 1416.232408]  [<ffffffff8105dc0d>] ? __init_kthread_worker+0x2d/0x2d
[ 1416.232490] Code: f0 48 8d 1c 0e 45 31 db 41 b9 80 00 00 00 eb 76 45 01 c9 41 81 f9 00 01 00 00 75 0b 44 8a 1f 66 41 b9 01 00 48 ff c7 41 0f b6 c3 <8a> 0f 44 85 c8 74 4b 0f b6 57 01 0f b6 c1 4d 89 c2 c1 e0 08 48 
[ 1416.235019] RIP  [<ffffffffa08db2f2>] lzjb_decompress+0x2e/0x92 [zfs]
[ 1416.235151]  RSP <ffff8803f77fbc08>
[ 1416.235223] CR2: ffffc90016598000
[ 1416.235296] ---[ end trace 85ccc37a76a21f83 ]---

Any ideas? This is unfortunately my main storage system, running zfs version '0.6.1-1.20130604' with zfs-crypto and some extra libshare patches that have yet to be merged to 0.6.2+.
It holds all my development VMs so building a new kernel and/or zfs/spl module(s) will be extremely difficult.

I have a new kernel and spl/zfs module built, but that's in my ZFS root which I have not been able to boot because of various problems, mostly grub.

I actually managed to find a '0.6.2-1.20130824' version of both spl and zfs which had the appropriate extra patches. Unfortunately, that exhibits the exact same behavior.

I've found a number of issues regarding 'spl_kmem_cache_alloc', but none match exactly, and those people have managed to at least load the module, but fail on import. My module won't even load. Sometimes, if I move '/sbin/zpool' out of the way, I can load the module but not import it (get the same problem as above), so maybe it's related... ?

@FransUrbo
Copy link
Contributor Author

Increasing vm.min_free_kbytes from 135168 to 4194304 (according to #1666), gives me:

[  193.097287] SPL: Loaded module v0.6.1-1.20130514.crypto.mine
[  212.303482] zunicode: module license 'CDDL' taints kernel.
[  212.303485] Disabling lock debugging due to kernel taint
[  213.157460] SPL: using hostid 0xa8c00845
[  214.107996] ZFS: Loaded module v0.6.1-1.20130604.iscsi.crypto.mine, ZFS pool version 5000, ZFS filesystem version 5
[  231.297021] BUG: unable to handle kernel paging request at ffffffffa0a1bfd8
[  231.297195] IP: [<ffffffffa09af7cd>] zio_buf_alloc+0xc/0x19 [zfs]
[  231.297340] PGD 14a1067 PUD 14a2063 PMD 40ded2067 PTE 0
[  231.297565] Oops: 0000 [#1] SMP 
[  231.297711] Modules linked in: zfs(PO) zcommon(PO) znvpair(PO) zavl(PO) zunicode(PO) spl(O) zlib_deflate binfmt_misc st appletalk psnap llc autofs4 crc32c nfsd nfs_acl auth_rpcgss nfs fscache lockd ib_iser rdma_cm ib_cm iw_cm ib_sa ib_mad ib_core ib_addr ipv6 iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi sunrpc dm_crypt nf_conntrack cpufreq_stats cpufreq_userspace it87 hwmon_vid i2c_dev loop eeepc_wmi asus_wmi sparse_keymap rfkill video pci_hotplug mxm_wmi evdev freq_table mperf snd_pcm_oss snd_mixer_oss microcode kvm_amd kvm snd_pcm snd_timer snd soundcore snd_page_alloc tpm_tis tpm tpm_bios k10temp i2c_piix4 i2c_core sp5100_tco pcspkr ehci_pci ehci_hcd wmi button processor ext3 jbd mbcache dm_mirror dm_region_hash dm_log dm_snapshot dm_mod sd_mod usb_storage firewire_ohci firewire_core crc_itu_t r8169 mii sata_mv mvsas libsas scsi_transport_sas ohci_hcd ahci libahci thermal fan thermal_sys nbd raid1 md_mod ide_gd_mod ide_core sata_sil libata scsi_mod
[  231.302336] CPU 4 
[  231.302381] Pid: 9294, comm: zpool Tainted: P           O 3.9.0-rc6+tf.1 #1 To be filled by O.E.M. To be filled by O.E.M./SABERTOOTH 990FX
[  231.302570] RIP: 0010:[<ffffffffa09af7cd>]  [<ffffffffa09af7cd>] zio_buf_alloc+0xc/0x19 [zfs]
[  231.302732] RSP: 0000:ffff8803f418b7b0  EFLAGS: 00210213
[  231.302811] RAX: 0000000084000000 RBX: 0000000000c39c00 RCX: 0000000000000004
[  231.302896] RDX: 0000000210000000 RSI: 0000000000000230 RDI: 00000000000061cd
[  231.302981] RBP: ffff8803ef608640 R08: 0000000021000000 R09: 0000000000c39c00
[  231.303065] R10: 0000000210000000 R11: 0000000000000010 R12: 0000000000000001
[  231.303150] R13: ffff8803f40da000 R14: ffffc90019010000 R15: ffffffffa092bc8c
[  231.303235] FS:  0000000000000000(0000) GS:ffff88041fd00000(0063) knlGS:00000000f6f6fb10
[  231.303348] CS:  0010 DS: 002b ES: 002b CR0: 000000008005003b
[  231.303428] CR2: ffffffffa0a1bfd8 CR3: 000000040abb4000 CR4: 00000000000007e0
[  231.303512] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  231.303597] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[  231.303683] Process zpool (pid: 9294, threadinfo ffff8803f418a000, task ffff88040c8cc800)
[  231.303795] Stack:
[  231.303862]  ffffffffa0928736 0000000000c39c00 ffff8803ef61d180 ffff8803ef608640
[  231.304119]  0000000000c39c00 ffff8803ef61d180 ffffffffa0928aa6 af4e60e5a21a3ef5
[  231.304375]  0000000000000000 af4e60e5a21a3ef5 0000000000000000 ffff8803f0b911e0
[  231.304631] Call Trace:
[  231.304711]  [<ffffffffa0928736>] ? arc_get_data_buf+0x1a5/0x3bc [zfs]
[  231.304804]  [<ffffffffa0928aa6>] ? arc_buf_alloc+0xb0/0xdc [zfs]
[  231.304894]  [<ffffffffa0928d5b>] ? arc_read_nolock+0x26b/0x6af [zfs]
[  231.304980]  [<ffffffffa087d8f1>] ? taskq_init_ent+0x3d/0x8b [spl]
[  231.305071]  [<ffffffffa09296d0>] ? arc_read+0xc2/0x16a [zfs]
[  231.305161]  [<ffffffffa09b1a82>] ? zio_null+0x5b/0x60 [zfs]
[  231.305251]  [<ffffffffa092bc8c>] ? dbuf_fill_done+0x61/0x61 [zfs]
[  231.305342]  [<ffffffffa092c632>] ? dbuf_read+0x407/0x64b [zfs]
[  231.305433]  [<ffffffffa092c9fc>] ? __dbuf_hold_impl+0x186/0x3bb [zfs]
[  231.305525]  [<ffffffffa092cca0>] ? dbuf_hold_impl+0x6f/0x8e [zfs]
[  231.305617]  [<ffffffffa092dc0d>] ? dbuf_hold+0x18/0x2b [zfs]
[  231.305708]  [<ffffffffa0941fde>] ? dnode_hold_impl+0x159/0x45f [zfs]
[  231.305801]  [<ffffffffa09322a3>] ? dmu_buf_hold+0x3f/0x17c [zfs]
[  231.305895]  [<ffffffffa0983899>] ? zap_lockdir+0x58/0x67b [zfs]
[  231.305979]  [<ffffffff8105e557>] ? __init_waitqueue_head+0x17/0x28
[  231.306072]  [<ffffffffa0937149>] ? dmu_objset_open_impl+0x58f/0x5d6 [zfs]
[  231.306168]  [<ffffffffa098530f>] ? zap_lookup_norm+0x3f/0x153 [zfs]
[  231.306263]  [<ffffffffa0985490>] ? zap_lookup+0x2a/0x32 [zfs]
[  231.306357]  [<ffffffffa0967203>] ? spa_load+0x7e4/0x1818 [zfs]
[  231.306450]  [<ffffffffa0985d25>] ? zcrypt_keystore_init+0x6c/0x8f [zfs]
[  231.306546]  [<ffffffffa096634d>] ? spa_activate+0x35a/0x369 [zfs]
[  231.306641]  [<ffffffffa09638b7>] ? spa_deactivate+0x1c4/0x20d [zfs]
[  231.306736]  [<ffffffffa096839d>] ? spa_load_best+0x166/0x1fc [zfs]
[  231.306831]  [<ffffffffa09688fc>] ? spa_open_common+0xf6/0x2d4 [zfs]
[  231.306925]  [<ffffffffa0995df7>] ? pool_status_check+0x20/0x72 [zfs]
[  231.307019]  [<ffffffffa0995f3d>] ? zfsdev_ioctl+0xf4/0x15f [zfs]
[  231.307103]  [<ffffffff8114f38b>] ? compat_sys_ioctl+0x1bf/0xf30
[  231.307185]  [<ffffffff8110f274>] ? vfs_read+0xaa/0x14e
[  231.307265]  [<ffffffff813591c9>] ? ia32_do_call+0x13/0x13
[  231.307344] Code: 00 e9 a9 a4 ec ff 48 ff cf be 30 02 00 00 48 c1 ef 09 48 8b 3c fd 70 b9 9e a0 e9 90 a4 ec ff 48 ff cf be 30 02 00 00 48 c1 ef 09 <48> 8b 3c fd 70 b1 9e a0 e9 77 a4 ec ff 41 55 41 54 49 89 f4 53 
[  231.309879] RIP  [<ffffffffa09af7cd>] zio_buf_alloc+0xc/0x19 [zfs]
[  231.310008]  RSP <ffff8803f418b7b0>
[  231.310080] CR2: ffffffffa0a1bfd8
[  231.310154] ---[ end trace 0498be886d32c2d5 ]---

@FransUrbo
Copy link
Contributor Author

Ok, so spending over a day getting a new kernel (3.12.0) and then latest spl+zfs checkout compiled, I managed to both load the module and also import the pool.

However:

  pool: share
 state: UNAVAIL
status: The pool can only be accessed in read-only mode on this system. It
    cannot be accessed in read-write mode because it uses the following
    feature(s) not supported on this system:
    com.sun:encryption

action: The pool cannot be accessed in read-write mode. Import the pool with
    "-o readonly=on", access the pool from a system that supports the
    required feature(s), or restore the pool from backup.
  scan: none requested

Now, the question is: Can I safely enable readonly (I can wait until zfs-rogue catches up - I have only one FS which is encrypted)?

@FransUrbo
Copy link
Contributor Author

Latest {spl,zfs}-crypto in his '0.6.3' branch seems to work. It was merged with ZoL at the 0c28fb4 (Fri Aug 16 15:20:07 2013 if I'm reading the log correctly) commit. After that, there have been a lot of changes to ZoL.

I did get ZFS-8000-72 however:

  pool: share
 state: FAULTED
status: The pool metadata is corrupted and the pool cannot be opened.
action: Recovery is possible, but will result in some data loss.
        Returning the pool to its state as of Fri Nov  8 01:26:48 2013
        should correct the problem.  Approximately 24 seconds of data
        must be discarded, irreversibly.  Recovery can be attempted
        by executing 'zpool clear -F share'.  A scrub of the pool
        is strongly recommended after recovery.
   see: http://zfsonlinux.org/msg/ZFS-8000-72
  scan: scrub repaired 0 in 86h4m with 0 errors on Fri Oct  4 20:56:29 2013
config:

        NAME                                    STATE     READ WRITE CKSUM
        share                                   FAULTED      0     0     0  corrupted data
          raidz1-0                              ONLINE       0     0     0
            scsi-SATA_ST3000DM001-9YN_Z1F0WJSN  ONLINE       0     0     0
            scsi-SATA_ST3000DM001-9YN_Z1F0X41F  ONLINE       0     0     0
            scsi-SATA_ST3000DM001-9YN_Z1F0X3P4  ONLINE       0     0     0
          raidz1-1                              ONLINE       0     0     0
            scsi-SATA_ST31500341AS_9VS4XK4T     ONLINE       0     0     0
            scsi-SATA_ST31500341AS_9VS4Q3F4     ONLINE       0     0     0
            scsi-SATA_ST1500DL003-9VT_5YD1F2KF  ONLINE       0     0     0
          raidz1-2                              ONLINE       0     0     0
            scsi-SATA_ST31500341AS_9VS3SAWS     ONLINE       0     0     0
            scsi-SATA_ST31500341AS_9VS4R2MJ     ONLINE       0     0     0
            scsi-SATA_ST31500341AS_9VS13W11     ONLINE       0     0     0
          raidz1-3                              ONLINE       0     0     0
            scsi-SATA_ST31500341AS_9VS4VT5R     ONLINE       0     0     0
            scsi-SATA_ST31500341AS_9VS4Q38C     ONLINE       0     0     0
            scsi-SATA_ST31500341AS_9VS4WM30     ONLINE       0     0     0
          raidz1-4                              ONLINE       0     0     0
            scsi-SATA_ST31500341AS_9VS4VT5X     ONLINE       0     0     0
            scsi-SATA_ST31500341AS_9VS4WWPA     ONLINE       0     0     0
            scsi-SATA_ST31500341AS_9VS0H3A9     ONLINE       0     0     0

I'm currently running the command and hopfully everything will be ok! I'm absolutly terrified though. I have not been able to find a cheap way to do a backup on 15Tb!!

@FransUrbo
Copy link
Contributor Author

CRAP!

celia:~# zpool clear -F share
cannot clear errors for share: I/O error

That gave me another oops:

[  241.513522] zpool           D ffff88041fcd4ac0     0 11257  10518 0x20020004
[  241.513525]  ffff8800da8ed000 0000000000200086 ffffffff810eb3ea ffffffff815e6000
[  241.513529]  ffff8800d2a7c010 0000000000014ac0 0000000000014ac0 ffff8800da8ed000
[  241.513532]  0000000000014ac0 ffff8800d2a7dfd8 ffff8800d2a7dfd8 0000000000014ac0
[  241.513534] Call Trace:
[  241.513541]  [<ffffffff810eb3ea>] ? __alloc_pages_nodemask+0x190/0x910
[  241.513545]  [<ffffffff8111ee39>] ? __kmalloc+0x138/0x1b5
[  241.513547]  [<ffffffff8111ee39>] ? __kmalloc+0x138/0x1b5
[  241.513549]  [<ffffffff810eac59>] ? get_page_from_freelist+0x48e/0x590
[  241.513552]  [<ffffffff8111ee39>] ? __kmalloc+0x138/0x1b5
[  241.513558]  [<ffffffffa08725da>] ? kmem_alloc_debug+0x141/0x2c9 [spl]
[  241.513561]  [<ffffffff813c41ab>] ? schedule_preempt_disabled+0x9/0xc
[  241.513564]  [<ffffffff813c1fd0>] ? __mutex_lock_slowpath+0x1ab/0x1f6
[  241.513568]  [<ffffffffa08f2413>] ? nv_mem_zalloc+0x12/0x2d [znvpair]
[  241.513571]  [<ffffffff813c1d72>] ? mutex_lock+0x12/0x22
[  241.513592]  [<ffffffffa0963952>] ? spa_all_configs+0x6d/0x108 [zfs]
[  241.513607]  [<ffffffffa098ba6e>] ? zfs_ioc_pool_configs+0x18/0x3c [zfs]
[  241.513622]  [<ffffffffa098e818>] ? zfsdev_ioctl+0x335/0x3c0 [zfs]
[  241.513625]  [<ffffffff8110e8a7>] ? page_add_new_anon_rmap+0x68/0x12a
[  241.513627]  [<ffffffff813c4d93>] ? _raw_spin_unlock+0x9/0xb
[  241.513630]  [<ffffffff81104fd7>] ? handle_mm_fault+0x9c3/0x9f8
[  241.513632]  [<ffffffff8110fe8f>] ? unlink_anon_vmas+0xee/0x17b
[  241.513636]  [<ffffffff81045eed>] ? do_page_fault+0x3ed/0x439
[  241.513639]  [<ffffffff81169163>] ? compat_sys_ioctl+0x1bf/0xf30
[  241.513641]  [<ffffffff8110a038>] ? remove_vma+0x44/0x4b
[  241.513643]  [<ffffffff8110b590>] ? do_munmap+0x2dd/0x2f9
[  241.513645]  [<ffffffff813c7909>] ? ia32_do_call+0x13/0x13

@FransUrbo
Copy link
Contributor Author

Installing the non-crypto versions of spl/zfs again (#1848 (comment)) and used the '-o readonly=on', I get:

cannot import 'share': I/O error
        Recovery is possible, but will result in some data loss.
        Returning the pool to its state as of Fri Nov  8 01:26:48 2013
        should correct the problem.  Approximately 24 seconds of data
        must be discarded, irreversibly.  After rewind, several
        persistent user-data errors will remain.  Recovery can be attempted
        by executing 'zpool import -F share'.  A scrub of the pool
        is strongly recommended after recovery.

An 'import -F' seemed to have worked, but now every time I run 'zpool status', I get a glibc memory corruption:

*** glibc detected *** zpool: malloc(): memory corruption: 0x08dcfad0 ***
======= Backtrace: =========
/lib/libc.so.6[0xf744f935]
/lib/libc.so.6[0xf7451ed2]
/lib/libc.so.6(__libc_malloc+0x96)[0xf7453676]
/lib/libnvpair.so.1[0xf76eacbd]
/lib/libnvpair.so.1(nvlist_xalloc+0x2e)[0xf76eb2fe]
/lib/libnvpair.so.1(nvlist_alloc+0x30)[0xf76eb3d0]
/lib/libzfs.so.2(zpool_get_errlog+0x220)[0xf755ab90]
zpool[0x80510d2]
zpool[0x804bd19]
zpool[0x804bfc6]
zpool[0x8056c8b]
zpool[0x8052408]
/lib/libc.so.6(__libc_start_main+0xe5)[0xf73fb455]
zpool[0x804bad1]

And after a reboot, I had to use 'import -F' again (probably because I can't run a scrub on a read-only pool)...

@FransUrbo
Copy link
Contributor Author

Going back to the spl/zfs crypto I built earlier (which is pre-libzfs_core), and this time using the parameter 'zvol_inhibit_dev=1', everything seems to be just dandy. So far. It's currently resilvering, so hopfully that won't fuck everything up.

I didn't need to use the option '-F' when I imported the pool. I had to use '-f' though (probably because it was previously imported with the non-crypto version):

zpool import -d /dev/disk/by-id -aNf

I still get the glibc memalloc stack trace on the subsequent 'zpool status', but 'zfs list' seems to work without a problem.

*** glibc detected *** zpool: malloc(): memory corruption: 0x085e0ab8 ***
[etc]

Full stack saved if any one is interested...

UPDATE: I only seem to get that the first time. I just ran it again (some five-ten minutes after the import), and this time I didn't get the stacktrace...

And the pool seems fine:

  pool: share
 state: ONLINE
 scan: resilvered 56.7M in 0h2m with 0 errors on Tue Nov 12 06:12:24 2013
 [...]
errors: No known data errors

@FransUrbo
Copy link
Contributor Author

Soooo.... My question(s) now...

  1. I'd really, really, REALLLLY (!!) would like to know what caused the problem in the first time! This is the first time I've heard of that ZoL silently 'fucks things up' on it's on. Crashes, oopses etc I've seen on the list and in the issue tracker, I've seen people messing things up (mostly because they did something they shouldn't :), but this is the first I've seen and heard of that is this severe.
  2. I know my spl/zfs version is way behind on ZoL and hopfully zfsrogue can catch up, but until then: Any idea why I get OOPSes when I don't use the 'zvol_inhibit_dev' parameter? The import freezes (because of first an oops in first zpool, txg_sync and then vol_id - which I don't seem to have included, but I have it saved locally if anyone is interested to see it).

I guest Q2 is more of a 'if someone have the time to investigate or already seen it and knows exactly what the fix is/was'. ZoL HEAD don't seem to exibit this problem (don't know if that's because I have to import using 'readonly=on' and that might mean something) so I can wait with Q2...

But Q1 is very serious and a reason really needs to be found (so that I and everyone else can be sure it won't happen again). I'm actually quite weery of mounting the filesystems now - I figure if I don't mount anything, it won't write anything to disk. I really don't even dare to reboot to verify that everything works!

@behlendorf
Copy link
Contributor

@FransUrbo First off I'm glad you see you managed to save the pool!

  1. I'd really, really, REALLLLY (!!) would like to know what caused the problem in the first time!

The first issue you encountered appear to be a somewhat unexplainable error down in the memory allocator. I've sporadically seen this sort of thing reported before and it almost always is the result of a build gone wrong. Either the spl was not rebuilt with zfs, or perhaps there was only a partial zfs build, or the linking phase went badly for strange reason. It's rare, but it's been reported. However, in all of these case no damage to the pool was ever done. The system would just panic/oops, rebuilding the modules cleanly usually would resolve the issue. I know that's not a very satisfying answer but it's hard to say for certain what happened.

Your pool also has the complication of the crypto bits. While I've never looked at that code, I can easily image that the ZoL upstream code might interpret a pool like this to have "corrupt" metadata.

  1. Any idea why I get OOPSes when I don't use the 'zvol_inhibit_dev' parameter?

No, that needs an explanation if someone has time to dig in to it.

@FransUrbo
Copy link
Contributor Author

@behlendorf 'A build gone wrong'... Could you elaborate?

I don't use dkms. Don't like it, don't trust it and I think it's a piece of utter crap. And it's a mess because I try to run all my machines on the same kernel so distributing a installable package with the binary modules in it is so much simpler than having a build environment on every single one of them...

So I always build the deb packages, and I always test them on a special VM before I install them on the main server (except this time because I can't access my VM's). And I never install a kernel module package unless I have the intention to reboot. So I can say with ... 98% certainty (based on how I work and my personal methodology - I leave 2% off because I HAVE been known to forget :).

So the original modules was installed and loaded in the beginning of june. And since I've had about two-three months uptime before I rebooted, that means I have rebooted that install at least once (I also usually reboot about every three-four months to upgrade spl/zfs just because I'd like to keep as close to HEAD as possible to gain features but mostly speed which still isn't great but just fine for my use case).

I can't absolutly rule out 'a build gone wrong' (especially since I'm not quite sure what you mean by that), but I'd say it is very unlikely - I know what I'm doing (famos last words, but still! :). I'm fairly certain I would have detected any troubles before hand.

Why would vanilla ZoL think that the pool is corrupted just because of the crypto bit? It DOES notice this (every time I tried) and refuses to import it read-write. In addition to refusing to import r/w, claiming it's corrupted, it also complains about I/O errors. I still get that from 'zdb', even though the pool is now imported (without accessible ZVOLs). I just haven't mounted the filesystems (other than test one or two of them and then unmounted them afterwards).

@behlendorf
Copy link
Contributor

@FransUrbo By a build gone wrong I just meant a build which might not have been carefully done. For example, say ZFS was accidentally built against version A of the SPL, but then version B of the SPL modules was loaded with your new modules. That doesn't sound like the case here but it can lead to all sorts of weird issues.

Why would vanilla ZoL think that the pool is corrupted just because of the crypto bit?

I'm just speculating since I've never tried this. But it's my understanding that the way ZFS encryption was done not all of the metadata gets encrypted. Enough of it remains in the clear that even vanilla ZoL can determine a little bit about the pool. I could imagine a case where it can see enough to attempt the import but quickly runs in to encrypted blocks which look it like corruption. But, as I said that's just a guess.

@FransUrbo
Copy link
Contributor Author

I could imagine a case where it can see enough to attempt the import but quickly runs in to encrypted blocks which look it like corruption.

Ok, doesn't seem to far fetched.

@FransUrbo
Copy link
Contributor Author

I'm closing this, because it's now quite obvious that it's the zfs-crypto patch that fucked everything up.

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

2 participants