Closed umask closed 9 years ago
This was very likely fixed by #2884. If possible could you try either.
xattr=sa
on the dataset. You can use the stable zfs repository for this.Okay, I will try (1) and report you about result.
zfs destroy data/101_srv_backup
is very slow. I have had to cleanup my 8 drives and create zpool from scratch.
Is it normal - I waited 1 hour but space in parent pool freed less than 100GB?
And one more strange fact. Is it normal that scrub speed in my config approx. 10-12MB/sec on raidz2?
I have tried (1). Using latest packages from zfs-testing repo (see versions in issue description) WITH xattr=sa
and I get kernel panic again.
Kernel panic message is too long for paste here. Please see it in gist: https://gist.github.com/umask/62b247f37107053ff791
This kernel panic occurred at first rsync when 6-7TB was transferred.
I have found messages in my logs
[25108.622770] sd 0:2:2:0: [sdc] megasas: RESET -7968430 cmd=28 retries=0
[25108.623345] megasas: [ 0]waiting for 1 commands to complete
[25109.623501] megaraid_sas: no pending cmds after reset
[25109.624075] megasas: reset successful
May be it's something connected with issue described in this ticket.
For clean experiment I erased disks, controller settings and created zpool from scratch. Now initial rsync is running again. Hope that no kernel panic will occur.
Panic again while initial rsync: '[175802.578978] BUG: scheduling while atomic: rsync/2932/0x14010000'.
While copying first 6-7TB of data all was OK. Next happened this warnings:
[165793.482413] INFO: task txg_sync:1247 blocked for more than 120 seconds.
[165793.482444] Tainted: P --------------- 2.6.32-042stab094.7 #1
[165793.482469] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[165793.482494] txg_sync D ffff880811150580 0 1247 2 0 0x00000000
[165793.482522] ffff88080a629b90 0000000000000046 ffff88080a629af0 ffffffff8105fff2
[165793.482552] ffff88080a629b40 ffffffff8100beae ffff88080a629b80 000000000000007d
[165793.482581] 0000000000000000 0000000000000001 ffff880811150b48 000000000001ecc0
[165793.482610] Call Trace:
[165793.482623] [<ffffffff8105fff2>] ? default_wake_function+0x12/0x20
[165793.482645] [<ffffffff8100beae>] ? call_function_interrupt+0xe/0x20
[165793.482668] [<ffffffff8152fb53>] io_schedule+0x73/0xc0
[165793.482698] [<ffffffffa027d74c>] cv_wait_common+0x8c/0x100 [spl]
[165793.482720] [<ffffffff810a1b60>] ? autoremove_wake_function+0x0/0x40
[165793.482744] [<ffffffffa027d7d8>] __cv_wait_io+0x18/0x20 [spl]
[165793.482788] [<ffffffffa03d31db>] zio_wait+0xfb/0x1b0 [zfs]
[165793.482824] [<ffffffffa035fd03>] dsl_pool_sync+0xb3/0x430 [zfs]
[165793.482862] [<ffffffffa0374fab>] spa_sync+0x44b/0xb70 [zfs]
[165793.482881] [<ffffffff81054939>] ? __wake_up_common+0x59/0x90
[165793.482901] [<ffffffff810592c3>] ? __wake_up+0x53/0x70
[165793.482920] [<ffffffff81015029>] ? read_tsc+0x9/0x20
[165793.482956] [<ffffffffa0389365>] txg_sync_thread+0x355/0x5b0 [zfs]
[165793.482977] [<ffffffff8106dc82>] ? enqueue_entity+0x52/0x280
[165793.483013] [<ffffffffa0389010>] ? txg_sync_thread+0x0/0x5b0 [zfs]
[165793.483050] [<ffffffffa0389010>] ? txg_sync_thread+0x0/0x5b0 [zfs]
[165793.483074] [<ffffffffa0279228>] thread_generic_wrapper+0x68/0x80 [spl]
[165793.483098] [<ffffffffa02791c0>] ? thread_generic_wrapper+0x0/0x80 [spl]
[165793.483120] [<ffffffff810a1546>] kthread+0x96/0xa0
[165793.483137] [<ffffffff8100c34a>] child_rip+0xa/0x20
[165793.483154] [<ffffffff810a14b0>] ? kthread+0x0/0xa0
[165793.483170] [<ffffffff8100c340>] ? child_rip+0x0/0x20
[166033.412997] INFO: task rsync:2934 blocked for more than 120 seconds.
[166033.413047] Tainted: P --------------- 2.6.32-042stab094.7 #1
[166033.413079] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[166033.413111] rsync D ffff880811126f30 0 2934 2932 101 0x00000080
[166033.413138] ffff880800fc1a98 0000000000000086 ffff8803a5e3db70 0000000000000282
[166033.413168] ffff880800fc1a78 ffff8803a5e3db70 ffff8803a5e3db70 ffff880816926800
[166033.413211] 0000000000000000 ffff88081ac00000 ffff8808111274f8 000000000001ecc0
[166033.413240] Call Trace:
[166033.413255] [<ffffffff810a1dae>] ? prepare_to_wait_exclusive+0x4e/0x80
[166033.413303] [<ffffffffa027d7ad>] cv_wait_common+0xed/0x100 [spl]
[166033.413324] [<ffffffff810a1b60>] ? autoremove_wake_function+0x0/0x40
[166033.413354] [<ffffffffa027d815>] __cv_wait+0x15/0x20 [spl]
[166033.413401] [<ffffffffa0349e8d>] dmu_tx_wait+0xad/0x340 [zfs]
[166033.413434] [<ffffffffa034a301>] dmu_tx_assign+0x91/0x490 [zfs]
[166033.414064] [<ffffffffa03c3a9b>] zfs_write+0x40b/0xc50 [zfs]
[166033.414687] [<ffffffff811ac40a>] ? do_sync_read+0xfa/0x140
[166033.415311] [<ffffffffa03d8b85>] zpl_write+0xa5/0x140 [zfs]
[166033.415914] [<ffffffff811ac5a8>] vfs_write+0xb8/0x1a0
[166033.416512] [<ffffffff811acf71>] sys_write+0x51/0x90
[166033.417087] [<ffffffff810f4cee>] ? __audit_syscall_exit+0x25e/0x290
[166033.417657] [<ffffffff8100b102>] system_call_fastpath+0x16/0x1b
[167233.071730] INFO: task rsync:2934 blocked for more than 120 seconds.
[167233.072310] Tainted: P --------------- 2.6.32-042stab094.7 #1
[167233.072897] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[167233.073483] rsync D ffff880811126f30 0 2934 2932 101 0x00000080
[167233.074082] ffff880800fc1a98 0000000000000086 0000000000000000 0000000000000282
[167233.074670] ffff880800fc1a78 ffff88080b92f310 ffff88080b92f310 ffff880816926800
[167233.075266] 0000000000000000 0000000109f0beb8 ffff8808111274f8 000000000001ecc0
[167233.075869] Call Trace:
[167233.076469] [<ffffffffa027d7ad>] cv_wait_common+0xed/0x100 [spl]
[167233.077070] [<ffffffff810a1b60>] ? autoremove_wake_function+0x0/0x40
[167233.077671] [<ffffffffa027d815>] __cv_wait+0x15/0x20 [spl]
[167233.078295] [<ffffffffa0349e8d>] dmu_tx_wait+0xad/0x340 [zfs]
[167233.078911] [<ffffffffa034a301>] dmu_tx_assign+0x91/0x490 [zfs]
[167233.079533] [<ffffffffa0357ffb>] ? dsl_dataset_block_freeable+0x4b/0x80 [zfs]
[167233.080155] [<ffffffffa0349b06>] ? dmu_tx_count_dnode+0x66/0xd0 [zfs]
[167233.080788] [<ffffffffa03c3a9b>] zfs_write+0x40b/0xc50 [zfs]
[167233.081420] [<ffffffffa03d8b85>] zpl_write+0xa5/0x140 [zfs]
[167233.082032] [<ffffffff811ac5a8>] vfs_write+0xb8/0x1a0
[167233.082636] [<ffffffff811acf71>] sys_write+0x51/0x90
[167233.083246] [<ffffffff810f4cee>] ? __audit_syscall_exit+0x25e/0x290
[167233.083866] [<ffffffff8100b102>] system_call_fastpath+0x16/0x1b
Probably this messages something connected with kernel panic which occurs after.
There is messages about kernel panic (too big to paste here):
https://gist.github.com/umask/04651d14729c16331c6e
(problem is the same as here https://gist.github.com/umask/62b247f37107053ff791)
@behlendorf , could you give me some advice? May be I need do not to use xattr=sa
?
I need to store backups on this server and if I do not make ZoL workable I will have to use ext3/4 with rdiff-backup (it's very slow...) :(
I'm trying to locate file/directory which rsync copying when kernel panic occurs...
Panic occurs on different files (random files in one directory?).
I have erased disks, controller settings and created zpool from scratch... again.
Now initial rsync is running.
xattr=on
(BY-DEFAULT) now.
(zfs packages still from testing repo)
@umask Here's a few notes. The original panic posted in this issue which had the following stack trace:
[ 8859.308567] [<ffffffffa03fb833>] zio_buf_alloc+0x23/0x30 [zfs]
[ 8859.309389] [<ffffffffa035dcb8>] arc_get_data_buf+0x498/0x4d0 [zfs]
[ 8859.310212] [<ffffffffa035e540>] arc_buf_alloc+0xf0/0x130 [zfs]
...
is most certainly caused by a corrupted dnode in which arbitrary data are used as a blkptr for a spill block.
Second, this type of corruption can definitely lead to filesystems which can't be destroyed via zfs destroy
.
Finally, the 4254acb patch should fix all cases of corrupted dnodes I'm aware of but it will not do anything for a filesystem which has already been corrupted. In fact, no fix commited to master (other than maybe 5f6d0b6f) will be of much assistance to an already-corrupted filesystem.
If you are able to create a filesystem with a corrupted dnode using a module containing 4254acb, I'd sure like to know about it. And, if so, please try to track down one of the corrupted files and/or directories and post the output of zdb -ddddd <pool>/<fs> <inode>
of it.
@dweeezil how I can determine corrupted file(s) and/or directory(ies)?
(I suspect one directory with 35GB of many subdirectories and files and I hope that problem occurs on it; otherwise I have to wait until ~7TB of data will by rsynced).
If I gets kernel crash dump using KDump - will it be enough to identify problem?
@umask The easiest way to identify the file with a bad dnode is to try to run a stat(2) on each file (typically by running a simple script). You can save time by trying directories first since they're most likely to become corrupted. Once you find a corrupted file and/or directory, start by running zdb -dddddd <pool>/<fs> <inode>
(where
I'd like to clarify how you're running into this problem: Are you creating a brand new ZFS filesystem with a module as of at least 4254acb (including all previous SA-related fixes) and then populating it with rsync and getting the corruption? Or is this an existing filesystem which was populated prior to all the SA fixes?
There is details how my zpool created and how I get kernel panic:
/* zfs/spl packages installed from zfs-testing repo */
# cat /var/log/dmesg | grep -E 'SPL:|ZFS:'
[ 9.150142] SPL: Loaded module v0.6.3-52_g52479ec
[ 9.306503] ZFS: Loaded module v0.6.3-159_gc944be5, ZFS pool version 5000, ZFS filesystem version 5
[ 10.651813] SPL: using hostid 0x00000000
# zpool create data raidz2 scsi-3600605b0058c11a01c176f05140bece1 scsi-3600605b0058c11a01c176f061412559a scsi-3600605b0058c11a01c176f061419ff77 scsi-3600605b0058c11a01c176f071421f0b0 scsi-3600605b0058c11a01c176f07142bc148 scsi-3600605b0058c11a01c176f0814354c3e scsi-3600605b0058c11a01c176f09143fadf8 scsi-3600605b0058c11a01c176f09144a8ef1 -m /mnt/data -f
# zfs create data/101_srv_backup
# zfs set checksum=sha256 data/101_srv_backup
# zfs set compression=gzip-7 data/101_srv_backup
# zfs set dedup=sha256,verify data/101_srv_backup
# zfs set acltype=posixacl data/101_srv_backup
# zfs set xattr=sa data/101_srv_backup
# zfs set atime=off data/101_srv_backup
/* rsync here runs in openvz container */
# rsync -aHAX --numeric-ids --relative --timeout=1500 --delete --delete-excluded --exclude-from=/root/rsync_exclude.txt root@server:/mnt/data /srv/backup/server/ --progress --stats -v
/* kernel panic occurs after few days of rsyncing when 6-7TB of data transferred */
i.e. ZFS filesystem created by latest available version of ZoL with all available SA-related fixes.
@dweeezil what about https://gist.github.com/umask/04651d14729c16331c6e https://gist.github.com/umask/62b247f37107053ff791 ?
Currently I'm running rsync with xattr=on
(BY-DEFAULT) to check that no kernel panic will happen. Unfortunately I stopped my previous the same test to check that transferring 35GB of suspected directory will produce panic. But panic didn't happen on this 35GB
I have setup kdump. Will its help if panic occurs?
@umask Neither of those sets of stack traces from the gists look to be SA/spill related (but they're very long and I've not looked too thoroughly at them yet). What kind of preemption is your kernel using? Settings other than CONFIG_PREEMPT_VOLUNTARY=y
have been known to cause problems.
This kernel .config parameters are standard for vzkernel (OpenVZ kernel for rhel6/centos6) and kernel from rhel6/centos6 vendors:
# cat /boot/config-2.6.32-042stab094.7 | grep PREEM
# CONFIG_TREE_PREEMPT_RCU is not set
CONFIG_PREEMPT_NOTIFIERS=y
# CONFIG_PREEMPT_NONE is not set
CONFIG_PREEMPT_VOLUNTARY=y
# CONFIG_PREEMPT is not set
Neither of those sets of stack traces from the gists look to be SA/spill related (but they're very long and I've not looked too thoroughly at them yet)
Both gists I got from two latest kernel panics. So, I'm waiting for my current test results. I will write about result here, in this ticket.
So, in result rsync completed successfully
...
2014/12/15 09:34:58 [535] Number of files: 14741651
2014/12/15 09:34:58 [535] Number of files transferred: 13965296
2014/12/15 09:34:58 [535] Total file size: 9697844213610 bytes
2014/12/15 09:34:58 [535] Total transferred file size: 9697844207468 bytes
2014/12/15 09:34:58 [535] Literal data: 9697849062964 bytes
2014/12/15 09:34:58 [535] Matched data: 0 bytes
2014/12/15 09:34:58 [535] File list size: 480287234
2014/12/15 09:34:58 [535] File list generation time: 0.008 seconds
2014/12/15 09:34:58 [535] File list transfer time: 0.000 seconds
2014/12/15 09:34:58 [535] Total bytes sent: 268448716
2014/12/15 09:34:58 [535] Total bytes received: 9700104109660
2014/12/15 09:34:58 [535] sent 268448716 bytes received 9700104109660 bytes 39090998.17 bytes/sec
2014/12/15 09:34:58 [535] total size is 9697844213610 speedup is 1.00
2014/12/15 09:34:58 [533] rsync warning: some files vanished before they could be transferred (code 24) at main.c(1505) [generator=3.0.6]
with xattr=on
(BY-DEFAULT).
Before this success I have tried xattr=sa
with kernel panics every time.
I have run rsync again on my dataset and no kernel panics occurs anymore.
I convinced that problem in xattr=sa
.
Unfortunately I have no possibility to reproduce problem on this server because I need consistent backups.
I'm setting up new one for tests.
@umask If there is still a lingering issue with SA xattrs and the manner in which they're typically used when acltype=posixacl
, I'd sure love to see the zdb -ddddd <pool>/<fs> <inode>
output from an affected file. If you can reproduce the problem, please try to isolate an affected file by traversing the filesystem with an ls -lR
and then trying ls -ld
on individual files and/or directories as you get close. Once you find one, get its inode number and run the zdb command.
Closing, all known SA fixes have been merged.
I'm running server with ZoL to save backups on it.
Short details about my config:
I have run stable version of ZoL which provided by this packages for centos 6:
No any problem happened while I make first backup using rsync. But after initial backup every time when I run rsync again kernel panic occurs.
I googled for the same problem https://github.com/zfsonlinux/zfs/issues/2701 and decided update zfs related packages using zfs-testing repo.
My current installed packages state is:
After reboot with new versions of zfs modules problem happened again.
There is backtrace for kernel panic with 0.6.3 from stable zfs repo:
There is backtrace for kernel panic with zfs modules from testing repo:
As you may note kernel panic occurs after 2 hours from server start. After server start I run rsync manually.
There are details about my config:
zpool created on this 8 virtual raid0 drives.
(I tried to run scrub, but speed was very slow and I stopped it; after update from zfs-testing repo I didn't proceed
zpool upgrade
).Additional details: