Hang when trying to access fs

Hang when trying to access fs

[Nikolaus Rath]

Hello,

When trying to rsync to btrfs, the process just hangs. dmesg output
alternates between:

Jan 28 09:42:49 vostro kernel: [  360.460076] INFO: task rsync:3484 blo=
cked for more than 120 seconds.
Jan 28 09:42:49 vostro kernel: [  360.460079] "echo 0 > /proc/sys/kerne=
l/hung_task_timeout_secs" disables this message.
Jan 28 09:42:49 vostro kernel: [  360.460081] rsync           D ffff880=
09d8d7850     0  3484      1 0x00000004
Jan 28 09:42:49 vostro kernel: [  360.460085]  ffff88009d8d7850 0000000=
000000082 0000000000000000 ffff88009b4d1810
Jan 28 09:42:49 vostro kernel: [  360.460089]  0000000000012f40 ffff880=
092361fd8 ffff880092361fd8 ffff88009d8d7850
Jan 28 09:42:49 vostro kernel: [  360.460092]  0000000000000246 fffffff=
f8132de1c ffff88009b5342f0 ffff880094051e80
Jan 28 09:42:49 vostro kernel: [  360.460096] Call Trace:
Jan 28 09:42:49 vostro kernel: [  360.460102]  [<ffffffff8132de1c>] ? _=
raw_spin_lock_irqsave+0x9/0x25
Jan 28 09:42:49 vostro kernel: [  360.460118]  [<ffffffffa05afd19>] ? w=
ait_current_trans.isra.22+0xae/0xdd [btrfs]
Jan 28 09:42:49 vostro kernel: [  360.460122]  [<ffffffff8105ec6b>] ? a=
dd_wait_queue+0x3c/0x3c
Jan 28 09:42:49 vostro kernel: [  360.460132]  [<ffffffffa05b0f82>] ? s=
tart_transaction+0x231/0x246 [btrfs]
Jan 28 09:42:49 vostro kernel: [  360.460144]  [<ffffffffa05b9772>] ? b=
trfs_dirty_inode+0x23/0x11d [btrfs]
Jan 28 09:42:49 vostro kernel: [  360.460148]  [<ffffffff8111001c>] ? _=
_mark_inode_dirty+0x22/0x17a
Jan 28 09:42:49 vostro kernel: [  360.460159]  [<ffffffffa05b891e>] ? b=
trfs_setattr+0x6d/0x92 [btrfs]
Jan 28 09:42:49 vostro kernel: [  360.460162]  [<ffffffff81107642>] ? n=
otify_change+0x18e/0x256
Jan 28 09:42:49 vostro kernel: [  360.460165]  [<ffffffff810353a7>] ? s=
hould_resched+0x5/0x23
Jan 28 09:42:49 vostro kernel: [  360.460168]  [<ffffffff81114930>] ? u=
times_common+0x10c/0x135
Jan 28 09:42:49 vostro kernel: [  360.460170]  [<ffffffff81114a14>] ? d=
o_utimes+0xbb/0xd6
Jan 28 09:42:49 vostro kernel: [  360.460173]  [<ffffffff810f779c>] ? s=
ys_newlstat+0x23/0x2b
Jan 28 09:42:49 vostro kernel: [  360.460175]  [<ffffffff810353a7>] ? s=
hould_resched+0x5/0x23
Jan 28 09:42:49 vostro kernel: [  360.460178]  [<ffffffff81114b1a>] ? s=
ys_utimensat+0x6e/0x77
Jan 28 09:42:49 vostro kernel: [  360.460181]  [<ffffffff81332e12>] ? s=
ystem_call_fastpath+0x16/0x1b

and

Jan 28 09:42:49 vostro kernel: [  360.460184] INFO: task rsync:3495 blo=
cked for more than 120 seconds.
Jan 28 09:42:49 vostro kernel: [  360.460185] "echo 0 > /proc/sys/kerne=
l/hung_task_timeout_secs" disables this message.
Jan 28 09:42:49 vostro kernel: [  360.460186] rsync           D ffff880=
0bfc92f40     0  3495      1 0x00000004
Jan 28 09:42:49 vostro kernel: [  360.460189]  ffff88009b4c47f0 0000000=
000000086 ffff880000000000 ffff8800bbf080c0
Jan 28 09:42:49 vostro kernel: [  360.460192]  0000000000012f40 ffff880=
091ff1fd8 ffff880091ff1fd8 ffff88009b4c47f0
Jan 28 09:42:49 vostro kernel: [  360.460196]  0000000000000000 0000000=
1bff5b700 ffffffff8102f71b ffff880094060a20
Jan 28 09:42:49 vostro kernel: [  360.460199] Call Trace:
Jan 28 09:42:49 vostro kernel: [  360.460202]  [<ffffffff8102f71b>] ? p=
te_alloc_one+0x2f/0x39
Jan 28 09:42:49 vostro kernel: [  360.460205]  [<ffffffff8132d437>] ? _=
_mutex_lock_common.isra.6+0xff/0x164
Jan 28 09:42:49 vostro kernel: [  360.460209]  [<ffffffff810cada2>] ? c=
opy_pte_range+0x34d/0x391
Jan 28 09:42:49 vostro kernel: [  360.460211]  [<ffffffff8132d325>] ? m=
utex_lock+0x1a/0x2d
Jan 28 09:42:49 vostro kernel: [  360.460214]  [<ffffffff810fcb6d>] ? w=
alk_component+0x1f4/0x406
Jan 28 09:42:49 vostro kernel: [  360.460217]  [<ffffffff8102f999>] ? p=
tep_set_access_flags+0x39/0x45
Jan 28 09:42:49 vostro kernel: [  360.460219]  [<ffffffff810fd9c1>] ? p=
ath_lookupat+0x7c/0x29e
Jan 28 09:42:49 vostro kernel: [  360.460222]  [<ffffffff810353a7>] ? s=
hould_resched+0x5/0x23
Jan 28 09:42:49 vostro kernel: [  360.460224]  [<ffffffff8132cb37>] ? _=
cond_resched+0x7/0x1c
Jan 28 09:42:49 vostro kernel: [  360.460227]  [<ffffffff810fdbff>] ? d=
o_path_lookup+0x1c/0x87
Jan 28 09:42:49 vostro kernel: [  360.460229]  [<ffffffff810ff47a>] ? u=
ser_path_at_empty+0x47/0x7b
Jan 28 09:42:49 vostro kernel: [  360.460232]  [<ffffffff81330dea>] ? d=
o_page_fault+0x2fc/0x337
Jan 28 09:42:49 vostro kernel: [  360.460234]  [<ffffffff810f7636>] ? v=
fs_fstatat+0x32/0x60
Jan 28 09:42:49 vostro kernel: [  360.460236]  [<ffffffff810f778b>] ? s=
ys_newlstat+0x12/0x2b
Jan 28 09:42:49 vostro kernel: [  360.460239]  [<ffffffff810353a7>] ? s=
hould_resched+0x5/0x23
Jan 28 09:42:49 vostro kernel: [  360.460241]  [<ffffffff8132e435>] ? p=
age_fault+0x25/0x30
Jan 28 09:42:49 vostro kernel: [  360.460244]  [<ffffffff81332e12>] ? s=
ystem_call_fastpath+0x16/0x1b


Kernel is 3.1.0. I'm writing to a 500 GB external USB disk.

Known bug? If not, anything I can do to help?


Best,

   -Nikolaus

--=20
 =C2=BBTime flies like an arrow, fruit flies like a Banana.=C2=AB

  PGP fingerprint: 5B93 61F8 4EA2 E279 ABF6  02CF A9AD B7F8 AE4E 425C
--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs" =
in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

blocked tasks right after mounting (was: Hang when trying to access fs)

[Nikolaus Rath]

Nikolaus Rath <Nikolaus@rath.org> writes:
> Hello,
>
> When trying to rsync to btrfs, the process just hangs. dmesg output
> alternates between:
[...]

I guess I should also mention that this is reproducible, and I don't
even need to run rsync. Simply mounting the file system produces a
similar warning soon afterwards:

[  678.316046] usb 1-4: new high speed USB device number 7 using ehci_h=
cd
[  678.448928] usb 1-4: New USB device found, idVendor=3D152d, idProduc=
t=3D2509
[  678.448931] usb 1-4: New USB device strings: Mfr=3D10, Product=3D11,=
 SerialNumber=3D3
[  678.448933] usb 1-4: Product: Usb production
[  678.448934] usb 1-4: Manufacturer: Jmicron Corp.
[  678.448936] usb 1-4: SerialNumber: 00A123456789
[  678.450429] scsi7 : usb-storage 1-4:1.0
[  681.372710] scsi 7:0:0:0: Direct-Access     WDC WD50 01AALS-00L3B2  =
  0000 PQ: 0 ANSI: 2 CCS
[  681.658185] sd 7:0:0:0: [sdg] 976773168 512-byte logical blocks: (50=
0 GB/465 GiB)
[  681.658925] sd 7:0:0:0: [sdg] Write Protect is off
[  681.658929] sd 7:0:0:0: [sdg] Mode Sense: 28 00 00 00
[  681.659675] sd 7:0:0:0: [sdg] No Caching mode page present
[  681.659679] sd 7:0:0:0: [sdg] Assuming drive cache: write through
[  681.662049] sd 7:0:0:0: [sdg] No Caching mode page present
[  681.662052] sd 7:0:0:0: [sdg] Assuming drive cache: write through
[  681.670316]  sdg: sdg1
[  681.673554] sd 7:0:0:0: [sdg] No Caching mode page present
[  681.673558] sd 7:0:0:0: [sdg] Assuming drive cache: write through
[  681.673562] sd 7:0:0:0: [sdg] Attached SCSI disk
[  791.512475] Btrfs loaded
[  791.513625] device label Videos devid 1 transid 142 /dev/mapper/udis=
ks-luks-uuid-7adf0c16-c741-485e-86dd-8a209fe4ce85-uid1000
[  791.567843] btrfs: disk space caching is enabled
[  960.456073] INFO: task sync:4930 blocked for more than 120 seconds.
[  960.456077] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disab=
les this message.
[  960.456080] sync            D ffff8800bfc92f40     0  4930      1 0x=
00000000
[  960.456085]  ffff88009f4d5790 0000000000000082 0000000000000000 ffff=
8800bbf080c0
[  960.456089]  0000000000012f40 ffff88009f4d7fd8 ffff88009f4d7fd8 ffff=
88009f4d5790
[  960.456094]  0000000000000246 000000018132de1c ffff880091d342f0 ffff=
88008686ae80
[  960.456098] Call Trace:
[  960.456117]  [<ffffffffa05aed19>] ? wait_current_trans.isra.22+0xae/=
0xdd [btrfs]
[  960.456123]  [<ffffffff8105ec6b>] ? add_wait_queue+0x3c/0x3c
[  960.456137]  [<ffffffffa05aff82>] ? start_transaction+0x231/0x246 [b=
trfs]
[  960.456141]  [<ffffffff81114543>] ? __sync_filesystem+0x6e/0x6e
[  960.456150]  [<ffffffffa0594357>] ? btrfs_sync_fs+0x79/0x95 [btrfs]
[  960.456153]  [<ffffffff8111452b>] ? __sync_filesystem+0x56/0x6e
[  960.456157]  [<ffffffff810f6578>] ? iterate_supers+0x5e/0xab
[  960.456160]  [<ffffffff811145cd>] ? sys_sync+0x3d/0x52
[  960.456164]  [<ffffffff81332e12>] ? system_call_fastpath+0x16/0x1b


Best,

   -Nikolaus

--=20
 =C2=BBTime flies like an arrow, fruit flies like a Banana.=C2=AB

  PGP fingerprint: 5B93 61F8 4EA2 E279 ABF6  02CF A9AD B7F8 AE4E 425C
--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs" =
in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: blocked tasks right after mounting (was: Hang when trying to access fs)

[Duncan]

Nikolaus Rath posted on Sat, 28 Jan 2012 10:23:53 -0500 as excerpted:

> Nikolaus Rath <Nikolaus@rath.org> writes:
>> Hello,
>>
>> When trying to rsync to btrfs, the process just hangs. dmesg output
>> alternates between:
> [...]
> 
> I guess I should also mention that this is reproducible, and I don't
> even need to run rsync. Simply mounting the file system produces a
> similar warning soon afterwards:
> 
> [  678.316046] usb 1-4: new high speed USB device number 7 using 
ehci_hcd

> [  678.450429] scsi7 : usb-storage 1-4:1.0

> [  681.659675] sd 7:0:0:0: [sdg] No Caching mode page present
> [  681.659679] sd 7:0:0:0: [sdg] Assuming drive cache: write through

> [  681.673562] sd 7:0:0:0: [sdg] Attached SCSI disk
> [  791.512475] Btrfs loaded
> [  791.513625] device label Videos devid 1 transid 142 /dev/mapper/
> udisks-luks-uuid-7adf0c16-c741-485e-86dd-8a209fe4ce85-uid1000
> [  791.567843] btrfs: disk space caching is enabled
> [  960.456073] INFO: task sync:4930 blocked for more than 120 seconds.

Two points, based on the wiki at:  https://btrfs.wiki.kernel.org/

1) In the first post you mention kernel 3.1.  Here's what the wiki has to 
say about kernel versions right at the top of the "Getting started" page:

>>>>>
btrfs is a fast-moving target. There are typically a great many bug fixes 
and enhancements between one kernel release and the next. Therefore:

** If you have btrfs filesystems, run the latest kernel.

If you are running a kernel two or more versions behind the latest one 
available from kernel.org, the first thing you will be asked to when you 
report a problem is to upgrade to the latest kernel.
<<<<<

It goes on to mention the userspace tools as well.  Note that the last 
btrfs-tools release version, (0.19 IIRC), is from (IIRC) 2010.  You 
REALLY want to be running a recently rebuilt live-git btrfs-tools build.

Elsewhere (I don't see the reference ATM) I believe I saw a 
recommendation to run the rc kernels as well (tho you might wish to wait 
until rc 3 or 4 just to be sure, I personally run git kernels but don't 
normally update during the merge window, so not until after rc1), for 
much the same reason -- they'll have fixes before a stable kernel will.

Given that we're past 3.3-rc1 at this point and there's been a couple 3.2-
stable updates, you really should be running at LEAST 3.2 stable, if not
3.3-rc1+.  3.1 is really a bit old, given that btrfs really /is/ still in 
heavy development.


2) I saw that /dev/mapper/udisks-luks-* message in the log and it 
reminded me of the following from the wiki gotchas page.  I don't run 
encryption here and thus haven't sorted out all the various encryption 
setups and don't know if luks is dm-crypt or something else, but it may 
apply regardless.  If you've had a power outage or unplugged without 
umounting, you're likely corrupted, and that's what's triggering your 
issue, since there's no indication that write-caching is turned off in 
the log you posted (tho it may not register in the log, I'll grant).

>>>>>
btrfs volumes on top of dm-crypt block devices (and possibly LVM) require 
write-caching to be turned off on the underlying HDD. Failing to do so, 
in the event of a power failure, may result in corruption not yet handled 
by btrfs code. (2.6.33) 
<<<<<

Despite the above warning, it may be that the first procedure listed at 
the top of the problem FAQ, zeroing out the log, may help, altho it's not 
clear from your post whether it actually mounted, or not.  You can try 
it.  There's also a note about the zero-log procedure in the (main) FAQ, 
under "Is btrfs stable", "Pragmantic, personal and anecdotal answer", 
which states (as of 2011-08-21):

>>>>>
In the last few months, the vast majority of the problems with broken and 
unmountable filesystems I've seen on IRC and the mailing list have been 
caused by power outages in the middle of a write to the FS, and have been 
fixable by use of the btrfs-zero-log tool.
<<<<<

But I'm not sure if that overrides the caveat on dm-crypt or if that has 
been fixed by now, since the dm-crypt note is from ~2010 since it 
mentions 2.6.33.

You can also try mounting read-only, which I found mentioned as a hint 
somewhere, as well, and there's a newer tool (that I don't see covered on 
the wiki, I read about it elsewhere) that will often let you at least 
copy the data out of a bad btrfs partition, if it's necessary.  That 
might allow you to get the data off, at least, if you don't have proper 
backups, which you DEFINITELY should have, given that btrfs is still 
experimental and under rapid development.

-- 
Duncan - List replies preferred.   No HTML msgs.
"Every nonfree program has a lord, a master --
and if you use the program, he is your master."  Richard Stallman

Re: blocked tasks right after mounting

[Nikolaus Rath]

Duncan <1i5t5.duncan@cox.net> writes:
> Nikolaus Rath posted on Sat, 28 Jan 2012 10:23:53 -0500 as excerpted:
>
>> Nikolaus Rath <Nikolaus@rath.org> writes:
>>> Hello,
>>>
>>> When trying to rsync to btrfs, the process just hangs. dmesg output
>>> alternates between:
>> [...]
>>=20
>> I guess I should also mention that this is reproducible, and I don't
>> even need to run rsync. Simply mounting the file system produces a
>> similar warning soon afterwards:
>>=20
>> [  678.316046] usb 1-4: new high speed USB device number 7 using=20
> ehci_hcd
>
>> [  678.450429] scsi7 : usb-storage 1-4:1.0
>
>> [  681.659675] sd 7:0:0:0: [sdg] No Caching mode page present
>> [  681.659679] sd 7:0:0:0: [sdg] Assuming drive cache: write through
>
>> [  681.673562] sd 7:0:0:0: [sdg] Attached SCSI disk
>> [  791.512475] Btrfs loaded
>> [  791.513625] device label Videos devid 1 transid 142 /dev/mapper/
>> udisks-luks-uuid-7adf0c16-c741-485e-86dd-8a209fe4ce85-uid1000
>> [  791.567843] btrfs: disk space caching is enabled
>> [  960.456073] INFO: task sync:4930 blocked for more than 120 second=
s.
>
> Two points, based on the wiki at:  https://btrfs.wiki.kernel.org/
[...]
>
> You can also try mounting read-only, which I found mentioned as a hin=
t=20
> somewhere, as well, and there's a newer tool (that I don't see covere=
d on=20
> the wiki, I read about it elsewhere) that will often let you at least=
=20
> copy the data out of a bad btrfs partition, if it's necessary.  That=20
> might allow you to get the data off, at least, if you don't have prop=
er=20
> backups, which you DEFINITELY should have, given that btrfs is still=20
> experimental and under rapid development.

There's no important data on the drive, and I have no personal interest
in getting this to work or debugging it further. I just wanted to repor=
t
this in case someone else would like to figure out what might be going
on here (in which case I'd be willing to assist).

Sorry if my mail gave the wrong impression. I meant to offer help if
that's an unknown bug, I didn't mean to ask for help :-).

Best,

   -Nikolaus

--=20
 =C2=BBTime flies like an arrow, fruit flies like a Banana.=C2=AB

  PGP fingerprint: 5B93 61F8 4EA2 E279 ABF6  02CF A9AD B7F8 AE4E 425C
--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs" =
in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: blocked tasks right after mounting

[Duncan]

Nikolaus Rath posted on Sat, 28 Jan 2012 23:07:20 -0500 as excerpted:

> Sorry if my mail gave the wrong impression. I meant to offer help if
> that's an unknown bug, I didn't mean to ask for help :-).

NP!  I'm just so used to interpreting posts as requests for help on the 
other lists I'm on, that in the absence of explicit wording to the 
contrary, I tend to do that here (where I know rather less about the 
topic, at least at this point, I'm learning) as well.

It's all good! =:^)

-- 
Duncan - List replies preferred.   No HTML msgs.
"Every nonfree program has a lord, a master --
and if you use the program, he is your master."  Richard Stallman