noguaran
2009-Aug-26 07:55 UTC
[zfs-code] [zfs-discuss] zpool import hangs with indefinite writes
Okay, I''m trying to do whatever I can NONDESTRUCTIVELY to fix this. I have almost 5TB of data that I can''t afford to lose (baby pictures and videos, etc.). Since no one has seen this problem before, maybe someone can tell me what I need to do to make a backup of what I have now so I can try other methods to recover this data. Just about everything I do starts writing to these drives, and that worries me. For example: zfs list - writes, zfs volinit - writes. I am hoping that I have not already ruined the existing data on these drives, but I do not know enough about ZFS to troubleshoot or test. I''m a little bit frustrated about this because I think I have everything I need, but I still can''t access anything: 64-bit - check, ECC RAM - check, redundancy (RAID-Z) - check. I don''t know if I''m not following the proper protocol for posting, and that is why I am not getting any responses, or what. At this point, I''m open to any suggestions (right or wrong). If the only way I''ll get any help is to pay for OpenSolaris support, let me know. -- This message posted from opensolaris.org
noguaran
2009-Aug-27 08:14 UTC
[zfs-code] [zfs-discuss] zpool import hangs with indefinite writes
Thank you so much for your reply! Here are the outputs:>1. Find PID of the hanging ''zpool import'', e.g. with ''ps -ef | grep zpool''root at mybox:~# ps -ef|grep zpool root 915 908 0 03:34:46 pts/3 0:00 grep zpool root 901 874 1 03:34:09 pts/2 0:00 zpool import drowning>2. Substitute PID with actual number in the below command >echo "0tPID::pid2proc|::walk thread|::findstack -v" | mdb -kroot at mybox:~# echo "0t901::pid2proc|::walk thread|::findstack -v" | mdb -k stack pointer for thread ffffff02ed8c7880: ffffff0010191a10 [ ffffff0010191a10 _resume_from_idle+0xf1() ] ffffff0010191a40 swtch+0x147() ffffff0010191a70 cv_wait+0x61(ffffff02eb010dda, ffffff02eb010d98) ffffff0010191ac0 txg_wait_synced+0x7f(ffffff02eb010c00, 31983c5) ffffff0010191b00 dsl_sync_task_group_wait+0xee(ffffff02f1d11bd8) ffffff0010191b80 dsl_sync_task_do+0x65(ffffff02eb010c00, fffffffff78be1f0, fffffffff78be250, ffffff02edc38400, ffffff0010191b98, 0) ffffff0010191bd0 dsl_dataset_rollback+0x53(ffffff02edc38400, 2) ffffff0010191c00 dmu_objset_rollback+0x46(ffffff02eb674b20) ffffff0010191c40 zfs_ioc_rollback+0x10d(ffffff02f2b58000) ffffff0010191cc0 zfsdev_ioctl+0x10b(b600000000, 5a1a, 803e240, 100003, ffffff02ee813338, ffffff0010191de4) ffffff0010191d00 cdev_ioctl+0x45(b600000000, 5a1a, 803e240, 100003, ffffff02ee813338, ffffff0010191de4) ffffff0010191d40 spec_ioctl+0x83(ffffff02df6a7480, 5a1a, 803e240, 100003, ffffff02ee813338, ffffff0010191de4, 0) ffffff0010191dc0 fop_ioctl+0x7b(ffffff02df6a7480, 5a1a, 803e240, 100003, ffffff02ee813338, ffffff0010191de4, 0) ffffff0010191ec0 ioctl+0x18e(3, 5a1a, 803e240) ffffff0010191f10 _sys_sysenter_post_swapgs+0x14b()>3. Do >echo "::spa" | mdb -kroot at mybox:~# echo "::spa" | mdb -k ADDR STATE NAME ffffff02f2b8b800 ACTIVE mypool ffffff02d5890000 ACTIVE rpool>4. Find address of your pool in the output of stage 3 and replace ADDR with it >in the below command (it is single line): >echo "ADDR::print spa_t spa_dsl_pool->dp_tx.tx_sync_thread|::findstack -v" | mdb -kroot at mybox:~# echo "ffffff02f2b8b800::print spa_t spa_dsl_pool->dp_tx.tx_sync_thread|::findstack -v" | mdb -k mdb: spa_t is not a struct or union type So I decided to remove "spa_t" to see what would happen: root at mybox:~# echo "ffffff02f2b8b800::print spa_dsl_pool->dp_tx.tx_sync_thread|::findstack -v" | mdb -k mdb: failed to look up type spa_dsl_pool->dp_tx.tx_sync_thread: no symbol corresponds to address>What do you mean by halt here? Are you able to interrupt ''zpool import'' with CTRL-C?Yes>Does ''zfs list'' provide any output?JACKPOT!!!!! When I run "zfs list", the import completes! Instead, "zfs list" hangs just like "zpool import" did. root at mybox:~# ps -ef | grep zfs root 940 874 0 03:49:15 pts/2 0:00 grep zfs root 936 908 0 03:44:28 pts/3 0:01 zfs list root at mybox:~# echo "0t936::pid2proc|::walk thread|::findstack -v" | mdb -k stack pointer for thread ffffff02d72ea020: ffffff000fdeaa10 [ ffffff000fdeaa10 _resume_from_idle+0xf1() ] ffffff000fdeaa40 swtch+0x147() ffffff000fdeaa70 cv_wait+0x61(ffffff02eb010dda, ffffff02eb010d98) ffffff000fdeaac0 txg_wait_synced+0x7f(ffffff02eb010c00, 31990da) ffffff000fdeab00 dsl_sync_task_group_wait+0xee(ffffff02f1d11bd8) ffffff000fdeab80 dsl_sync_task_do+0x65(ffffff02eb010c00, fffffffff78be1f0, fffffffff78be250, ffffff02f1d0ce00, ffffff000fdeab98, 0) ffffff000fdeabd0 dsl_dataset_rollback+0x53(ffffff02f1d0ce00, 2) ffffff000fdeac00 dmu_objset_rollback+0x46(ffffff02eb3322a8) ffffff000fdeac40 zfs_ioc_rollback+0x10d(ffffff02ebf4e000) ffffff000fdeacc0 zfsdev_ioctl+0x10b(b600000000, 5a1a, 8043a20, 100003, ffffff02ee813e78, ffffff000fdeade4) ffffff000fdead00 cdev_ioctl+0x45(b600000000, 5a1a, 8043a20, 100003, ffffff02ee813e78, ffffff000fdeade4) ffffff000fdead40 spec_ioctl+0x83(ffffff02df6a7480, 5a1a, 8043a20, 100003, ffffff02ee813e78, ffffff000fdeade4, 0) ffffff000fdeadc0 fop_ioctl+0x7b(ffffff02df6a7480, 5a1a, 8043a20, 100003, ffffff02ee813e78, ffffff000fdeade4, 0) ffffff000fdeaec0 ioctl+0x18e(3, 5a1a, 8043a20) ffffff000fdeaf10 _sys_sysenter_post_swapgs+0x14b()>Apparently as you have 5TB of data there, it worked fine some time ago. What >happened to the pool before this issue was noticed?A reboot? This box acts as network storage for all of my computers. All of the PCs in the house are set to back up to it daily, and it is like an extra hard drive for my wife''s netbook and laptop. We dump all of the pictures off of the camera there as well as any HD video we capture. I NEVER reboot this box unless I am prompted to. I''m running OpenSolaris (uname -a: SunOS mybox 5.11 snv_111b i86pc i386 i86pc Solaris), and if I remember right, I was prompted to update. I did so, and needed to reboot. Rebooted, and the box would not start. I used another PC to find out how to start in single user mode and tried that. No dice. I had to physically remove the drives to get to a login prompt. BTW, I just stopped the "zfs list" after about 30 minutes running, and it was constantly writing to my drives. (used ''zpool iostat 1'' to check) I am by no means an expert, but whatever "zfs list" is trying to do, it is hanging. Right now, my goal is to back up all of my important data. Once I do that, I will delete this pool and start over from scratch. My biggest concern is to keep this from happening again. Any suggestions? -- This message posted from opensolaris.org
noguaran
2009-Aug-27 08:51 UTC
[zfs-code] [zfs-discuss] zpool import hangs with indefinite writes
I used the GUI to delete all my snapshots, and after that, "zfs list" worked without hanging. I did a "zpool scrub" and will wait to see what happens with that. I DID have automatic snapshots enabled before. They are disabled now. I don''t know how the snapshots work to be honest, so maybe I ran into some upper limit with the amount of snapshots? I AM running daily backups on all computers: Windows, Linux, and Mac OS. -- This message posted from opensolaris.org
Victor Latushkin
2009-Aug-27 11:35 UTC
[zfs-code] [zfs-discuss] zpool import hangs with indefinite writes
On 27.08.09 12:14, noguaran wrote:> Thank you so much for your reply! > Here are the outputs: > >> 1. Find PID of the hanging ''zpool import'', e.g. with ''ps -ef | grep zpool'' > root at mybox:~# ps -ef|grep zpool > root 915 908 0 03:34:46 pts/3 0:00 grep zpool > root 901 874 1 03:34:09 pts/2 0:00 zpool import drowning > >> 2. Substitute PID with actual number in the below command >> echo "0tPID::pid2proc|::walk thread|::findstack -v" | mdb -k > > root at mybox:~# echo "0t901::pid2proc|::walk thread|::findstack -v" | mdb -k > stack pointer for thread ffffff02ed8c7880: ffffff0010191a10 > [ ffffff0010191a10 _resume_from_idle+0xf1() ] > ffffff0010191a40 swtch+0x147() > ffffff0010191a70 cv_wait+0x61(ffffff02eb010dda, ffffff02eb010d98) > ffffff0010191ac0 txg_wait_synced+0x7f(ffffff02eb010c00, 31983c5) > ffffff0010191b00 dsl_sync_task_group_wait+0xee(ffffff02f1d11bd8) > ffffff0010191b80 dsl_sync_task_do+0x65(ffffff02eb010c00, fffffffff78be1f0, > fffffffff78be250, ffffff02edc38400, ffffff0010191b98, 0) > ffffff0010191bd0 dsl_dataset_rollback+0x53(ffffff02edc38400, 2) > ffffff0010191c00 dmu_objset_rollback+0x46(ffffff02eb674b20) > ffffff0010191c40 zfs_ioc_rollback+0x10d(ffffff02f2b58000) > ffffff0010191cc0 zfsdev_ioctl+0x10b(b600000000, 5a1a, 803e240, 100003, > ffffff02ee813338, ffffff0010191de4) > ffffff0010191d00 cdev_ioctl+0x45(b600000000, 5a1a, 803e240, 100003, > ffffff02ee813338, ffffff0010191de4) > ffffff0010191d40 spec_ioctl+0x83(ffffff02df6a7480, 5a1a, 803e240, 100003, > ffffff02ee813338, ffffff0010191de4, 0) > ffffff0010191dc0 fop_ioctl+0x7b(ffffff02df6a7480, 5a1a, 803e240, 100003, > ffffff02ee813338, ffffff0010191de4, 0) > ffffff0010191ec0 ioctl+0x18e(3, 5a1a, 803e240) > ffffff0010191f10 _sys_sysenter_post_swapgs+0x14b()This tells us that it is doing some snapshot rollbacks as part of an import. Ouput of ''zpool history'' would help to see what commands were executed and provide better idea why it is doing that.>> 3. Do >> echo "::spa" | mdb -k > > root at mybox:~# echo "::spa" | mdb -k > ADDR STATE NAME > ffffff02f2b8b800 ACTIVE mypool > ffffff02d5890000 ACTIVE rpool > >> 4. Find address of your pool in the output of stage 3 and replace ADDR with it >> in the below command (it is single line): >> echo "ADDR::print spa_t spa_dsl_pool->dp_tx.tx_sync_thread|::findstack -v" | mdb -k > > root at mybox:~# echo "ffffff02f2b8b800::print spa_t spa_dsl_pool->dp_tx.tx_sync_thread|::findstack -v" | mdb -k > mdb: spa_t is not a struct or union type > > So I decided to remove "spa_t" to see what would happen:actually you need to replace ''spa_t'' with ''struct spa'', but anyway it does not matter much.> root at mybox:~# echo "ffffff02f2b8b800::print spa_dsl_pool->dp_tx.tx_sync_thread|::findstack -v" | mdb -k > mdb: failed to look up type spa_dsl_pool->dp_tx.tx_sync_thread: no symbol corresponds to address > >> What do you mean by halt here? Are you able to interrupt ''zpool import'' with CTRL-C? > YesOk, this is another confirmation that import is not hung in-kernel. Looks like its doing some housecleaning as part of mounting filesystems.>> Does ''zfs list'' provide any output? > JACKPOT!!!!! When I run "zfs list", the import completes! Instead, "zfs list" hangs just like "zpool import" did.Looks like it is working but slowly (or repeating the same operation constantly), hence it appears like hung.> > root at mybox:~# ps -ef | grep zfs > root 940 874 0 03:49:15 pts/2 0:00 grep zfs > root 936 908 0 03:44:28 pts/3 0:01 zfs list > > root at mybox:~# echo "0t936::pid2proc|::walk thread|::findstack -v" | mdb -k > stack pointer for thread ffffff02d72ea020: ffffff000fdeaa10 > [ ffffff000fdeaa10 _resume_from_idle+0xf1() ] > ffffff000fdeaa40 swtch+0x147() > ffffff000fdeaa70 cv_wait+0x61(ffffff02eb010dda, ffffff02eb010d98) > ffffff000fdeaac0 txg_wait_synced+0x7f(ffffff02eb010c00, 31990da) > ffffff000fdeab00 dsl_sync_task_group_wait+0xee(ffffff02f1d11bd8) > ffffff000fdeab80 dsl_sync_task_do+0x65(ffffff02eb010c00, fffffffff78be1f0, > fffffffff78be250, ffffff02f1d0ce00, ffffff000fdeab98, 0) > ffffff000fdeabd0 dsl_dataset_rollback+0x53(ffffff02f1d0ce00, 2) > ffffff000fdeac00 dmu_objset_rollback+0x46(ffffff02eb3322a8) > ffffff000fdeac40 zfs_ioc_rollback+0x10d(ffffff02ebf4e000) > ffffff000fdeacc0 zfsdev_ioctl+0x10b(b600000000, 5a1a, 8043a20, 100003, > ffffff02ee813e78, ffffff000fdeade4) > ffffff000fdead00 cdev_ioctl+0x45(b600000000, 5a1a, 8043a20, 100003, > ffffff02ee813e78, ffffff000fdeade4) > ffffff000fdead40 spec_ioctl+0x83(ffffff02df6a7480, 5a1a, 8043a20, 100003, > ffffff02ee813e78, ffffff000fdeade4, 0) > ffffff000fdeadc0 fop_ioctl+0x7b(ffffff02df6a7480, 5a1a, 8043a20, 100003, > ffffff02ee813e78, ffffff000fdeade4, 0) > ffffff000fdeaec0 ioctl+0x18e(3, 5a1a, 8043a20) > ffffff000fdeaf10 _sys_sysenter_post_swapgs+0x14b() > > >> Apparently as you have 5TB of data there, it worked fine some time ago. What >> happened to the pool before this issue was noticed? > A reboot? > This box acts as network storage for all of my computers. All of the PCs in the house are set to back up to it daily, and it is like an extra hard drive for my wife''s netbook and laptop. We dump all of the pictures off of the camera there as well as any HD video we capture. I NEVER reboot this box unless I am prompted to. I''m running OpenSolaris (uname -a: SunOS mybox 5.11 snv_111b i86pc i386 i86pc Solaris), and if I remember right, I was prompted to update. I did so, and needed to reboot. Rebooted, and the box would not start. I used another PC to find out how to start in single user mode and tried that. No dice. I had to physically remove the drives to get to a login prompt. BTW, I just stopped the "zfs list" after about 30 minutes running, and it was constantly writing to my drives. (used ''zpool iostat 1'' to check) I am by no means an expert, but whatever "zfs list" is trying to do, it is hanging. > > Right now, my goal is to back up all of my important data. Once I do that, I will delete this pool and start over from scratch. My biggest concern is to keep this from happening again. Any suggestions?
I have a somewhat similar problem.
My pool was created under FreeBSD.
pool: mass
id: 17237791880291344463
state: DEGRADED
action: The pool can be imported despite missing or damaged devices. The
fault tolerance of the pool may be compromised if imported.
config:
mass DEGRADED
raidz1 DEGRADED
ad8 ONLINE
replacing DEGRADED
ad10 ONLINE
7166408809693659020 FAULTED corrupted data
ad14 ONLINE
ad12 ONLINE
One of hdds started producing DMA errors. I tried to replace it but failed
because zpool commands just hung.
Soon the drive was back to normal and the pool worked again though the status
''replacing'' remained and I couldn''t remove
7166408809693659020.
Then one day I couldn''t import it anymore. zpool import was getting
stuck.
I tried running Solaris in the VirtualBox.
After invoking `zpool import -f mass` a lot of data is read from the disks then
a little is written and then it sits there and waits.
It looks like every zpool and zfs command hangs too.
sol-nv-b98-x86-v1, osol-0906-x86, osol-1002-123-x86 -- no difference.
Removing c9t1d0p0 symlink doesn''t help so it''s probably not
connected to ''replacing'' state.
Currently there is no evidence of any problems with the hdds, the unfortunate
one has 5 reallocated sectors.
jack at opensolaris:/dev/rdsk# zpool import
pool: mass
id: 17237791880291344463
state: DEGRADED
status: The pool was last accessed by another system.
action: The pool can be imported despite missing or damaged devices. The
fault tolerance of the pool may be compromised if imported.
see: http://www.sun.com/msg/ZFS-8000-EY
config:
mass DEGRADED
raidz1 DEGRADED
c9t0d0p0 ONLINE
replacing DEGRADED
c9t1d0p0 ONLINE
7166408809693659020 UNAVAIL cannot open
c9t3d0p0 ONLINE
c9t2d0p0 ONLINE
jack at opensolaris:~# zdb -l /dev/rdsk/c9t0d0p0
--------------------------------------------
LABEL 0
--------------------------------------------
version=13
name=''mass''
state=0
txg=56673850
pool_guid=17237791880291344463
hostid=3705723203
hostname=''hostname''
top_guid=17208459754718949456
guid=15572876870803484326
vdev_tree
type=''raidz''
id=0
guid=17208459754718949456
nparity=1
metaslab_array=14
metaslab_shift=34
ashift=9
asize=2000412475392
is_log=0
children[0]
type=''disk''
id=0
guid=15572876870803484326
path=''/dev/ad8''
whole_disk=0
DTL=55
children[1]
type=''replacing''
id=1
guid=16446985611132454904
whole_disk=0
children[0]
type=''disk''
id=0
guid=10380122112867903132
path=''/dev/ad10''
whole_disk=0
DTL=54
children[1]
type=''disk''
id=1
guid=7166408809693659020
path=''/dev/ad10''
whole_disk=0
not_present=1
DTL=209
children[2]
type=''disk''
id=2
guid=5186164191909664446
path=''/dev/ad14''
whole_disk=0
DTL=53
children[3]
type=''disk''
id=3
guid=16038735897748748777
path=''/dev/ad12''
whole_disk=0
DTL=52
--------------------------------------------
LABEL 1
--------------------------------------------
version=13
name=''mass''
state=0
txg=56673850
pool_guid=17237791880291344463
hostid=3705723203
hostname=''hostname''
top_guid=17208459754718949456
guid=15572876870803484326
vdev_tree
type=''raidz''
id=0
guid=17208459754718949456
nparity=1
metaslab_array=14
metaslab_shift=34
ashift=9
asize=2000412475392
is_log=0
children[0]
type=''disk''
id=0
guid=15572876870803484326
path=''/dev/ad8''
whole_disk=0
DTL=55
children[1]
type=''replacing''
id=1
guid=16446985611132454904
whole_disk=0
children[0]
type=''disk''
id=0
guid=10380122112867903132
path=''/dev/ad10''
whole_disk=0
DTL=54
children[1]
type=''disk''
id=1
guid=7166408809693659020
path=''/dev/ad10''
whole_disk=0
not_present=1
DTL=209
children[2]
type=''disk''
id=2
guid=5186164191909664446
path=''/dev/ad14''
whole_disk=0
DTL=53
children[3]
type=''disk''
id=3
guid=16038735897748748777
path=''/dev/ad12''
whole_disk=0
DTL=52
--------------------------------------------
LABEL 2
--------------------------------------------
version=13
name=''mass''
state=0
txg=56673850
pool_guid=17237791880291344463
hostid=3705723203
hostname=''hostname''
top_guid=17208459754718949456
guid=15572876870803484326
vdev_tree
type=''raidz''
id=0
guid=17208459754718949456
nparity=1
metaslab_array=14
metaslab_shift=34
ashift=9
asize=2000412475392
is_log=0
children[0]
type=''disk''
id=0
guid=15572876870803484326
path=''/dev/ad8''
whole_disk=0
DTL=55
children[1]
type=''replacing''
id=1
guid=16446985611132454904
whole_disk=0
children[0]
type=''disk''
id=0
guid=10380122112867903132
path=''/dev/ad10''
whole_disk=0
DTL=54
children[1]
type=''disk''
id=1
guid=7166408809693659020
path=''/dev/ad10''
whole_disk=0
not_present=1
DTL=209
children[2]
type=''disk''
id=2
guid=5186164191909664446
path=''/dev/ad14''
whole_disk=0
DTL=53
children[3]
type=''disk''
id=3
guid=16038735897748748777
path=''/dev/ad12''
whole_disk=0
DTL=52
--------------------------------------------
LABEL 3
--------------------------------------------
version=13
name=''mass''
state=0
txg=56673850
pool_guid=17237791880291344463
hostid=3705723203
hostname=''hostname''
top_guid=17208459754718949456
guid=15572876870803484326
vdev_tree
type=''raidz''
id=0
guid=17208459754718949456
nparity=1
metaslab_array=14
metaslab_shift=34
ashift=9
asize=2000412475392
is_log=0
children[0]
type=''disk''
id=0
guid=15572876870803484326
path=''/dev/ad8''
whole_disk=0
DTL=55
children[1]
type=''replacing''
id=1
guid=16446985611132454904
whole_disk=0
children[0]
type=''disk''
id=0
guid=10380122112867903132
path=''/dev/ad10''
whole_disk=0
DTL=54
children[1]
type=''disk''
id=1
guid=7166408809693659020
path=''/dev/ad10''
whole_disk=0
not_present=1
DTL=209
children[2]
type=''disk''
id=2
guid=5186164191909664446
path=''/dev/ad14''
whole_disk=0
DTL=53
children[3]
type=''disk''
id=3
guid=16038735897748748777
path=''/dev/ad12''
whole_disk=0
DTL=52
jack at opensolaris:/dev/rdsk# zpool import -f mass
jack at opensolaris:~# echo "0t959::pid2proc|::walk thread|::findstack
-v" | mdb -k
stack pointer for thread d44a8340: d38dcc24
d38dcc64 swtch+0x188()
d38dcc74 cv_wait+0x53(d8c8b9a6, d8c8b968, d38dccb4, f95c4741)
d38dccb4 txg_wait_synced+0x90(d8c8b800, 0, 0, 2)
d38dcd34 spa_load+0xe51(d4e76380, d46954d0, 2, 1)
d38dcd84 spa_import_common+0xc3()
d38dcdb4 spa_import+0x18(d4b0a000, d46954d0, 0, f95ed844)
d38dcde4 zfs_ioc_pool_import+0xcd(d4b0a000, 0, 0)
d38dce14 zfsdev_ioctl+0xe0()
d38dce44 cdev_ioctl+0x31(2d80000, 5a02, 80420c0, 100003, d8837f28, d38dcf00)
d38dce74 spec_ioctl+0x6b(d39b0e80, 5a02, 80420c0, 100003, d8837f28, d38dcf00)
d38dcec4 fop_ioctl+0x49(d39b0e80, 5a02, 80420c0, 100003, d8837f28, d38dcf00)
d38dcf84 ioctl+0x171()
d38dcfac sys_call+0x10c()
jack at opensolaris:~# echo "d4e76380::print struct spa
spa_dsl_pool->dp_tx.tx_sync_thread|::findstack -v" | mdb -k
stack pointer for thread d8e1fdc0: d8e1fbd8
d8e1fc18 swtch+0x188()
d8e1fc28 cv_wait+0x53(dc0eca68, dc0eca60, 0, 0)
d8e1fc58 zio_wait+0x55(dc0ec820, dc0ec820)
d8e1fcb8 dsl_pool_sync+0x24f(d8c8b800, 360c63b, 0)
d8e1fd28 spa_sync+0x452(d4e76380, 360c63b, 0, 0)
d8e1fda8 txg_sync_thread+0x308(d8c8b800, 0)
d8e1fdb8 thread_start+8()
jack at opensolaris:~#
--
This message posted from opensolaris.org