BUG: 2.6.14/2.6.15: USB storage/ext2fs uninterruptable sleep

BUG: 2.6.14/2.6.15: USB storage/ext2fs uninterruptable sleep

[Roger Leigh]

Hi folks,

I use a USB storage device (Kingston 128 MiB keydrive) to hold GPG
keys, which is automounted with autofs4.  It's looking like a write
operation on the device (so far always involving an ext2_delete_inode
up to sync_buffer) causes the process to hang in an uninterruptable
sleep.

The system is running stock kernel.org linux-2.6.15 and 2.6.14.5 on a
PowerPC 7447A system (Mac Mini) running Debian unstable.  The .config
is here: http://www.whinlatter.ukfsn.org/config-2.6.15-hardknott.bz2

For example:
# cd /misc/pen-secure/.gnupg
# rm secring.gpg.lock pubring.gpg.lock pubring.gpg.tmp

7818 pts/1    D+     0:00 rm secring.gpg.lock pubring.gpg.lock pubring.gpg.tmp

rm            D 0FF35634     0  7818   7196                   (NOTLB)
Call trace:
 [c0007524] __switch_to+0x54/0x6c
 [c0287c28] schedule+0x584/0x634
 [c0287d08] io_schedule+0x30/0x60
 [c006be78] sync_buffer+0x50/0x64
 [c0288854] __wait_on_bit_lock+0x60/0xc0
 [c0288928] out_of_line_wait_on_bit_lock+0x74/0x88
 [c006b33c] __lock_buffer+0x3c/0x4c
 [c006c570] sync_dirty_buffer+0x58/0x130
 [e2eef13c] ext2_xattr_delete_inode+0x1bc/0x278 [ext2]
 [e2ee8324] ext2_free_inode+0x38/0x27c [ext2]
 [e2eeb0a8] ext2_delete_inode+0x8c/0xac [ext2] [c00863b0] generic_delete_inode+0x104/0x17c
 [c0085450] iput+0x9c/0xb0
 [c007b09c] sys_unlink+0x124/0x180
 [c00046dc] ret_from_syscall+0x0/0x44

I have had the same with the entry point being sys_rename:

[gpg --recv-key ...]

gpg           D 0F6D76B4     0 19099   3976 19103               (NOTLB)
Call trace:
 [c0007524] __switch_to+0x54/0x6c
 [c0287c28] schedule+0x584/0x634
 [c0287d08] io_schedule+0x30/0x60
 [c006be78] sync_buffer+0x50/0x64
 [c0288854] __wait_on_bit_lock+0x60/0xc0
 [c0288928] out_of_line_wait_on_bit_lock+0x74/0x88
 [c006b33c] __lock_buffer+0x3c/0x4c
 [c006c570] sync_dirty_buffer+0x58/0x130
 [e2eaf13c] ext2_xattr_delete_inode+0x1bc/0x278 [ext2]
 [e2ea8324] ext2_free_inode+0x38/0x27c [ext2]
 [e2eab0a8] ext2_delete_inode+0x8c/0xac [ext2] [c00863b0] generic_delete_inode+0x104/0x17c
 [c0085450] iput+0x9c/0xb0
 [c0083b14] dput+0x234/0x264
 [c007b908] sys_rename+0x168/0x1c4

I can write other files to the device without trouble, but it's
clearly getting stuck somewhere inside the kernel.  In all the times
it's happened so far, eventually pdflush will subsequently go into D
state, and it's downhill from there (I can't unmount the filesystems
properly, and shutdown also hangs, so have to use Alt-SysRq to remount
readonly and reboot).

The device is using usb-storage, rather than ub:
$ cat /proc/partitions |grep sda
   8     0     125952 sda
   8     1      97776 sda1
   8     2      28160 sda2


I'll be happy to provide any additional details or do any further
testing.


Regards,
Roger

-- 
Roger Leigh
                Printing on GNU/Linux?  http://gimp-print.sourceforge.net/
                Debian GNU/Linux        http://www.debian.org/
                GPG Public Key: 0x25BFB848.  Please sign and encrypt your mail.

Re: BUG: 2.6.14/2.6.15: USB storage/ext2fs uninterruptable sleep

[Roger Leigh]

Roger Leigh <rleigh@whinlatter.ukfsn.org> writes:

> Hi folks,
>
> I use a USB storage device (Kingston 128 MiB keydrive) to hold GPG
> keys, which is automounted with autofs4.  It's looking like a write
> operation on the device (so far always involving an ext2_delete_inode
> up to sync_buffer) causes the process to hang in an uninterruptable
> sleep.
>
> The system is running stock kernel.org linux-2.6.15 and 2.6.14.5 on a
> PowerPC 7447A system (Mac Mini) running Debian unstable.  The .config
> is here: http://www.whinlatter.ukfsn.org/config-2.6.15-hardknott.bz2

This does not appear to occur with 2.6.13.  On 2.6.15, it occurs only
when accessing the device through the autofs4 mount; it works
perfectly if mounted by hand.  This looks like it might be an autofs4
regression.


Regards,
Roger

-- 
Roger Leigh
                Printing on GNU/Linux?  http://gimp-print.sourceforge.net/
                Debian GNU/Linux        http://www.debian.org/
                GPG Public Key: 0x25BFB848.  Please sign and encrypt your mail.

Re: BUG: 2.6.14/2.6.15: USB storage/ext2fs uninterruptable sleep

[Andrew Morton]

Roger Leigh <rleigh@whinlatter.ukfsn.org> wrote:
>
> Hi folks,
> 
> I use a USB storage device (Kingston 128 MiB keydrive) to hold GPG
> keys, which is automounted with autofs4.  It's looking like a write
> operation on the device (so far always involving an ext2_delete_inode
> up to sync_buffer) causes the process to hang in an uninterruptable
> sleep.
> 
> The system is running stock kernel.org linux-2.6.15 and 2.6.14.5 on a
> PowerPC 7447A system (Mac Mini) running Debian unstable.  The .config
> is here: http://www.whinlatter.ukfsn.org/config-2.6.15-hardknott.bz2
> 
> For example:
> # cd /misc/pen-secure/.gnupg
> # rm secring.gpg.lock pubring.gpg.lock pubring.gpg.tmp
> 
> 7818 pts/1    D+     0:00 rm secring.gpg.lock pubring.gpg.lock pubring.gpg.tmp
> 
> rm            D 0FF35634     0  7818   7196                   (NOTLB)
> Call trace:
>  [c0007524] __switch_to+0x54/0x6c
>  [c0287c28] schedule+0x584/0x634
>  [c0287d08] io_schedule+0x30/0x60
>  [c006be78] sync_buffer+0x50/0x64
>  [c0288854] __wait_on_bit_lock+0x60/0xc0
>  [c0288928] out_of_line_wait_on_bit_lock+0x74/0x88
>  [c006b33c] __lock_buffer+0x3c/0x4c
>  [c006c570] sync_dirty_buffer+0x58/0x130
>  [e2eef13c] ext2_xattr_delete_inode+0x1bc/0x278 [ext2]
>  [e2ee8324] ext2_free_inode+0x38/0x27c [ext2]
>  [e2eeb0a8] ext2_delete_inode+0x8c/0xac [ext2] [c00863b0] generic_delete_inode+0x104/0x17c
>  [c0085450] iput+0x9c/0xb0
>  [c007b09c] sys_unlink+0x124/0x180
>  [c00046dc] ret_from_syscall+0x0/0x44
> 
> I have had the same with the entry point being sys_rename:
> 
> [gpg --recv-key ...]
> 
> gpg           D 0F6D76B4     0 19099   3976 19103               (NOTLB)
> Call trace:
>  [c0007524] __switch_to+0x54/0x6c
>  [c0287c28] schedule+0x584/0x634
>  [c0287d08] io_schedule+0x30/0x60
>  [c006be78] sync_buffer+0x50/0x64
>  [c0288854] __wait_on_bit_lock+0x60/0xc0
>  [c0288928] out_of_line_wait_on_bit_lock+0x74/0x88
>  [c006b33c] __lock_buffer+0x3c/0x4c
>  [c006c570] sync_dirty_buffer+0x58/0x130
>  [e2eaf13c] ext2_xattr_delete_inode+0x1bc/0x278 [ext2]
>  [e2ea8324] ext2_free_inode+0x38/0x27c [ext2]
>  [e2eab0a8] ext2_delete_inode+0x8c/0xac [ext2] [c00863b0] generic_delete_inode+0x104/0x17c
>  [c0085450] iput+0x9c/0xb0
>  [c0083b14] dput+0x234/0x264
>  [c007b908] sys_rename+0x168/0x1c4
> 
> I can write other files to the device without trouble, but it's
> clearly getting stuck somewhere inside the kernel.  In all the times
> it's happened so far, eventually pdflush will subsequently go into D
> state, and it's downhill from there (I can't unmount the filesystems
> properly, and shutdown also hangs, so have to use Alt-SysRq to remount
> readonly and reboot).
> 
> The device is using usb-storage, rather than ub:
> $ cat /proc/partitions |grep sda
>    8     0     125952 sda
>    8     1      97776 sda1
>    8     2      28160 sda2
> 
> 
> I'll be happy to provide any additional details or do any further
> testing.
> 

I'd say that usb-storage is failing to send back I/O completions.

Re: BUG: 2.6.14/2.6.15: USB storage/ext2fs uninterruptable sleep

[Roger Leigh]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Andrew Morton <akpm@osdl.org> writes:

> Roger Leigh <rleigh@whinlatter.ukfsn.org> wrote:
>>
>> Hi folks,
>>
>> I use a USB storage device (Kingston 128 MiB keydrive) to hold GPG
>> keys, which is automounted with autofs4.  It's looking like a write
>> operation on the device (so far always involving an ext2_delete_inode
>> up to sync_buffer) causes the process to hang in an uninterruptable
>> sleep.
>>
>> The system is running stock kernel.org linux-2.6.15 and 2.6.14.5 on a
>> PowerPC 7447A system (Mac Mini) running Debian unstable.  The .config
>> is here: http://www.whinlatter.ukfsn.org/config-2.6.15-hardknott.bz2
>>
>> For example:
>> # cd /misc/pen-secure/.gnupg
>> # rm secring.gpg.lock pubring.gpg.lock pubring.gpg.tmp
>>
>> 7818 pts/1    D+     0:00 rm secring.gpg.lock pubring.gpg.lock pubring.gpg.tmp
>>
>> rm            D 0FF35634     0  7818   7196                   (NOTLB)
>> Call trace:
>>  [c0007524] __switch_to+0x54/0x6c
>>  [c0287c28] schedule+0x584/0x634
>>  [c0287d08] io_schedule+0x30/0x60
>>  [c006be78] sync_buffer+0x50/0x64
>>  [c0288854] __wait_on_bit_lock+0x60/0xc0
>>  [c0288928] out_of_line_wait_on_bit_lock+0x74/0x88
>>  [c006b33c] __lock_buffer+0x3c/0x4c
>>  [c006c570] sync_dirty_buffer+0x58/0x130
>>  [e2eef13c] ext2_xattr_delete_inode+0x1bc/0x278 [ext2]
>>  [e2ee8324] ext2_free_inode+0x38/0x27c [ext2]
>>  [e2eeb0a8] ext2_delete_inode+0x8c/0xac [ext2] [c00863b0] generic_delete_inode+0x104/0x17c
>>  [c0085450] iput+0x9c/0xb0
>>  [c007b09c] sys_unlink+0x124/0x180
>>  [c00046dc] ret_from_syscall+0x0/0x44
>>
>> I have had the same with the entry point being sys_rename:
>>
>> [gpg --recv-key ...]
>>
>> gpg           D 0F6D76B4     0 19099   3976 19103               (NOTLB)
>> Call trace:
>>  [c0007524] __switch_to+0x54/0x6c
>>  [c0287c28] schedule+0x584/0x634
>>  [c0287d08] io_schedule+0x30/0x60
>>  [c006be78] sync_buffer+0x50/0x64
>>  [c0288854] __wait_on_bit_lock+0x60/0xc0
>>  [c0288928] out_of_line_wait_on_bit_lock+0x74/0x88
>>  [c006b33c] __lock_buffer+0x3c/0x4c
>>  [c006c570] sync_dirty_buffer+0x58/0x130
>>  [e2eaf13c] ext2_xattr_delete_inode+0x1bc/0x278 [ext2]
>>  [e2ea8324] ext2_free_inode+0x38/0x27c [ext2]
>>  [e2eab0a8] ext2_delete_inode+0x8c/0xac [ext2] [c00863b0] generic_delete_inode+0x104/0x17c
>>  [c0085450] iput+0x9c/0xb0
>>  [c0083b14] dput+0x234/0x264
>>  [c007b908] sys_rename+0x168/0x1c4
>>
>> I can write other files to the device without trouble, but it's
>> clearly getting stuck somewhere inside the kernel.  In all the times
>> it's happened so far, eventually pdflush will subsequently go into D
>> state, and it's downhill from there (I can't unmount the filesystems
>> properly, and shutdown also hangs, so have to use Alt-SysRq to remount
>> readonly and reboot).
>>
>> The device is using usb-storage, rather than ub:
>> $ cat /proc/partitions |grep sda
>>    8     0     125952 sda
>>    8     1      97776 sda1
>>    8     2      28160 sda2
>>
>>
>> I'll be happy to provide any additional details or do any further
>> testing.

> I'd say that usb-storage is failing to send back I/O completions.

With some further testing with both usb-storage and ub, both show the
same behaviour when using autofs4 _or_ autofs.  When mounting by hand,
the problem does not occur.  While broken on 2.6.15 and 2.6.14, it
does appear to work on 2.6.13; I can't test earlier kernels at the
moment because of udev--I'll have to remove it first.

Using this simple test to exercise the device:
  while true; do cp /etc/fstab fstab; cat fstab; mv fstab t2; cat t2; rm t2; done
I quickly get a lockup with autofs4/autofs, with the device read/write
light lit up continuously.  When I run on a normal mount, the light
flashes once and then remains unlit (since there's nothing to write).
I'm not sure if this observation means autofs is doing something
wrong, but it does look like it's the main part of the problem.

I've CC'd the autofs list and maintainer, in case they can shed any
light on this.


Thanks,
Roger

- -- 
Roger Leigh
                Printing on GNU/Linux?  http://gimp-print.sourceforge.net/
                Debian GNU/Linux        http://www.debian.org/
                GPG Public Key: 0x25BFB848.  Please sign and encrypt your mail.
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.2 (GNU/Linux)
Comment: Processed by Mailcrypt 3.5.8+ <http://mailcrypt.sourceforge.net/>

iD8DBQFDvUJkVcFcaSW/uEgRAgpKAKCVvBmabzCtIKLafQv0tw7qHymx+gCfee5L
eP3COOtKcAY+StFV203JsPQ=
=OztQ
-----END PGP SIGNATURE-----

Re: [linux-usb-devel] Re: BUG: 2.6.14/2.6.15: USB storage/ext2fs uninterruptable sleep

[Alan Stern]

On Thu, 5 Jan 2006, Roger Leigh wrote:

> With some further testing with both usb-storage and ub, both show the
> same behaviour when using autofs4 _or_ autofs.  When mounting by hand,
> the problem does not occur.  While broken on 2.6.15 and 2.6.14, it
> does appear to work on 2.6.13; I can't test earlier kernels at the
> moment because of udev--I'll have to remove it first.

By any chance, does autofs or autofs4 mount your device with -o sync?  
Doing that with flash memory devices is a grave mistake -- although it 
shouldn't cause the sort of lock-up you described.

Alan Stern

Re: BUG: 2.6.14/2.6.15: USB storage/ext2fs uninterruptable sleep

[Ian Kent]

On Thu, 5 Jan 2006, Roger Leigh wrote:

> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA1
> 
> Andrew Morton <akpm@osdl.org> writes:
> 
> > Roger Leigh <rleigh@whinlatter.ukfsn.org> wrote:
> >>
> >> Hi folks,
> >>
> >> I use a USB storage device (Kingston 128 MiB keydrive) to hold GPG
> >> keys, which is automounted with autofs4.  It's looking like a write
> >> operation on the device (so far always involving an ext2_delete_inode
> >> up to sync_buffer) causes the process to hang in an uninterruptable
> >> sleep.
> >>
> >> The system is running stock kernel.org linux-2.6.15 and 2.6.14.5 on a
> >> PowerPC 7447A system (Mac Mini) running Debian unstable.  The .config
> >> is here: http://www.whinlatter.ukfsn.org/config-2.6.15-hardknott.bz2
> >>
> >> For example:
> >> # cd /misc/pen-secure/.gnupg
> >> # rm secring.gpg.lock pubring.gpg.lock pubring.gpg.tmp
> >>
> >> 7818 pts/1    D+     0:00 rm secring.gpg.lock pubring.gpg.lock pubring.gpg.tmp
> >>
> >> rm            D 0FF35634     0  7818   7196                   (NOTLB)
> >> Call trace:
> >>  [c0007524] __switch_to+0x54/0x6c
> >>  [c0287c28] schedule+0x584/0x634
> >>  [c0287d08] io_schedule+0x30/0x60
> >>  [c006be78] sync_buffer+0x50/0x64
> >>  [c0288854] __wait_on_bit_lock+0x60/0xc0
> >>  [c0288928] out_of_line_wait_on_bit_lock+0x74/0x88
> >>  [c006b33c] __lock_buffer+0x3c/0x4c
> >>  [c006c570] sync_dirty_buffer+0x58/0x130
> >>  [e2eef13c] ext2_xattr_delete_inode+0x1bc/0x278 [ext2]
> >>  [e2ee8324] ext2_free_inode+0x38/0x27c [ext2]
> >>  [e2eeb0a8] ext2_delete_inode+0x8c/0xac [ext2] [c00863b0] generic_delete_inode+0x104/0x17c
> >>  [c0085450] iput+0x9c/0xb0
> >>  [c007b09c] sys_unlink+0x124/0x180
> >>  [c00046dc] ret_from_syscall+0x0/0x44
> >>
> >> I have had the same with the entry point being sys_rename:
> >>
> >> [gpg --recv-key ...]
> >>
> >> gpg           D 0F6D76B4     0 19099   3976 19103               (NOTLB)
> >> Call trace:
> >>  [c0007524] __switch_to+0x54/0x6c
> >>  [c0287c28] schedule+0x584/0x634
> >>  [c0287d08] io_schedule+0x30/0x60
> >>  [c006be78] sync_buffer+0x50/0x64
> >>  [c0288854] __wait_on_bit_lock+0x60/0xc0
> >>  [c0288928] out_of_line_wait_on_bit_lock+0x74/0x88
> >>  [c006b33c] __lock_buffer+0x3c/0x4c
> >>  [c006c570] sync_dirty_buffer+0x58/0x130
> >>  [e2eaf13c] ext2_xattr_delete_inode+0x1bc/0x278 [ext2]
> >>  [e2ea8324] ext2_free_inode+0x38/0x27c [ext2]
> >>  [e2eab0a8] ext2_delete_inode+0x8c/0xac [ext2] [c00863b0] generic_delete_inode+0x104/0x17c
> >>  [c0085450] iput+0x9c/0xb0
> >>  [c0083b14] dput+0x234/0x264
> >>  [c007b908] sys_rename+0x168/0x1c4
> >>
> >> I can write other files to the device without trouble, but it's
> >> clearly getting stuck somewhere inside the kernel.  In all the times
> >> it's happened so far, eventually pdflush will subsequently go into D
> >> state, and it's downhill from there (I can't unmount the filesystems
> >> properly, and shutdown also hangs, so have to use Alt-SysRq to remount
> >> readonly and reboot).
> >>
> >> The device is using usb-storage, rather than ub:
> >> $ cat /proc/partitions |grep sda
> >>    8     0     125952 sda
> >>    8     1      97776 sda1
> >>    8     2      28160 sda2
> >>
> >>
> >> I'll be happy to provide any additional details or do any further
> >> testing.
> 
> > I'd say that usb-storage is failing to send back I/O completions.
> 
> With some further testing with both usb-storage and ub, both show the
> same behaviour when using autofs4 _or_ autofs.  When mounting by hand,
> the problem does not occur.  While broken on 2.6.15 and 2.6.14, it
> does appear to work on 2.6.13; I can't test earlier kernels at the
> moment because of udev--I'll have to remove it first.
> 
> Using this simple test to exercise the device:
>   while true; do cp /etc/fstab fstab; cat fstab; mv fstab t2; cat t2; rm t2; done
> I quickly get a lockup with autofs4/autofs, with the device read/write
> light lit up continuously.  When I run on a normal mount, the light
> flashes once and then remains unlit (since there's nothing to write).
> I'm not sure if this observation means autofs is doing something
> wrong, but it does look like it's the main part of the problem.

It's hard to understand how autofs4 could be interfering here as this is 
happening inside the filesystem.

It may be instructive to define DEBUG in the module (uncomment the 
define in autofs_i.h) and send the output.

Ian

Re: [linux-usb-devel] Re: BUG: 2.6.14/2.6.15: USB storage/ext2fs uninterruptable sleep

[Roger Leigh]

[-- Attachment #1: Type: text/plain, Size: 1209 bytes --]

Alan Stern <stern@rowland.harvard.edu> writes:

> On Thu, 5 Jan 2006, Roger Leigh wrote:
>
>> With some further testing with both usb-storage and ub, both show the
>> same behaviour when using autofs4 _or_ autofs.  When mounting by hand,
>> the problem does not occur.  While broken on 2.6.15 and 2.6.14, it
>> does appear to work on 2.6.13; I can't test earlier kernels at the
>> moment because of udev--I'll have to remove it first.
>
> By any chance, does autofs or autofs4 mount your device with -o sync?  
> Doing that with flash memory devices is a grave mistake -- although it 
> shouldn't cause the sort of lock-up you described.

Yes.  I have

pen-secure  -fstype=ext2,sync,nodev,nosuid,noatime  :/dev/sda2

in /etc/auto.misc.  Removing the sync option does prevent the lockups.
I just added it back and it locked up immediately.

The usb/usb-storage logs are attached (device mount + command which
broke it).  Would you like any more information?


Regards,
Roger

-- 
Roger Leigh
                Printing on GNU/Linux?  http://gimp-print.sourceforge.net/
                Debian GNU/Linux        http://www.debian.org/
                GPG Public Key: 0x25BFB848.  Please sign and encrypt your mail.

[-- Attachment #2: kern.log --]
[-- Type: text/plain, Size: 3316 bytes --]

Jan  5 17:31:44 hardknott kernel: usb-storage: queuecommand called
Jan  5 17:31:44 hardknott kernel: usb-storage: *** thread awakened.
Jan  5 17:31:44 hardknott kernel: usb-storage: Command WRITE_10 (10 bytes)
Jan  5 17:31:44 hardknott kernel: usb-storage:  2a 00 00 02 fc 02 00 00 04 00
Jan  5 17:31:44 hardknott kernel: usb-storage: Bulk Command S 0x43425355 T 0xea L 2048 F 0 Trg 0 LUN 0 CL 10
Jan  5 17:31:44 hardknott kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Jan  5 17:31:44 hardknott kernel: usb-storage: Status code 0; transferred 31/31
Jan  5 17:31:44 hardknott kernel: usb-storage: -- transfer complete
Jan  5 17:31:44 hardknott kernel: usb-storage: Bulk command transfer result=0
Jan  5 17:31:44 hardknott kernel: usb-storage: usb_stor_bulk_transfer_sglist: xfer 2048 bytes, 1 entries
Jan  5 17:31:44 hardknott kernel: usb-storage: Status code 0; transferred 2048/2048
Jan  5 17:31:44 hardknott kernel: usb-storage: -- transfer complete
Jan  5 17:31:44 hardknott kernel: usb-storage: Bulk data transfer result 0x0
Jan  5 17:31:44 hardknott kernel: usb-storage: Attempting to get CSW...
Jan  5 17:31:44 hardknott kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Jan  5 17:31:44 hardknott kernel: usb-storage: Status code 0; transferred 13/13
Jan  5 17:31:44 hardknott kernel: usb-storage: -- transfer complete
Jan  5 17:31:44 hardknott kernel: usb-storage: Bulk status result = 0
Jan  5 17:31:44 hardknott kernel: usb-storage: Bulk Status S 0x53425355 T 0xea R 0 Stat 0x0
Jan  5 17:31:44 hardknott kernel: usb-storage: scsi cmd done, result=0x0
Jan  5 17:31:44 hardknott kernel: usb-storage: *** thread sleeping.
Jan  5 17:31:55 hardknott kernel: usb-storage: queuecommand called
Jan  5 17:31:55 hardknott kernel: usb-storage: *** thread awakened.
Jan  5 17:31:55 hardknott kernel: usb-storage: Command WRITE_10 (10 bytes)
Jan  5 17:31:55 hardknott kernel: usb-storage:  2a 00 00 02 fc 0a 00 00 02 00
Jan  5 17:31:55 hardknott kernel: usb-storage: Bulk Command S 0x43425355 T 0xeb L 1024 F 0 Trg 0 LUN 0 CL 10
Jan  5 17:31:55 hardknott kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Jan  5 17:31:55 hardknott kernel: usb-storage: Status code 0; transferred 31/31
Jan  5 17:31:55 hardknott kernel: usb-storage: -- transfer complete
Jan  5 17:31:55 hardknott kernel: usb-storage: Bulk command transfer result=0
Jan  5 17:31:55 hardknott kernel: usb-storage: usb_stor_bulk_transfer_sglist: xfer 1024 bytes, 1 entries
Jan  5 17:31:55 hardknott kernel: usb-storage: Status code 0; transferred 1024/1024
Jan  5 17:31:55 hardknott kernel: usb-storage: -- transfer complete
Jan  5 17:31:55 hardknott kernel: usb-storage: Bulk data transfer result 0x0
Jan  5 17:31:55 hardknott kernel: usb-storage: Attempting to get CSW...
Jan  5 17:31:55 hardknott kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Jan  5 17:31:55 hardknott kernel: usb-storage: Status code 0; transferred 13/13
Jan  5 17:31:55 hardknott kernel: usb-storage: -- transfer complete
Jan  5 17:31:55 hardknott kernel: usb-storage: Bulk status result = 0
Jan  5 17:31:55 hardknott kernel: usb-storage: Bulk Status S 0x53425355 T 0xeb R 0 Stat 0x0
Jan  5 17:31:55 hardknott kernel: usb-storage: scsi cmd done, result=0x0
Jan  5 17:31:55 hardknott kernel: usb-storage: *** thread sleeping.

Re: [linux-usb-devel] Re: BUG: 2.6.14/2.6.15: USB storage/ext2fs uninterruptable sleep

[Alan Stern]

On Thu, 5 Jan 2006, Roger Leigh wrote:

> > By any chance, does autofs or autofs4 mount your device with -o sync?  
> > Doing that with flash memory devices is a grave mistake -- although it 
> > shouldn't cause the sort of lock-up you described.
> 
> Yes.  I have
> 
> pen-secure  -fstype=ext2,sync,nodev,nosuid,noatime  :/dev/sda2
> 
> in /etc/auto.misc.  Removing the sync option does prevent the lockups.
> I just added it back and it locked up immediately.

Sync for flash devices is generally a bad idea.  Especially with vfat 
filesystems but to some extent with all of them, it causes constant 
rewriting of sectors containing metadata.  Flash memory behaves poorly 
when the same sector gets written over and over again; it tends to slow 
down and eventually wear out completely.

> The usb/usb-storage logs are attached (device mount + command which
> broke it).  Would you like any more information?

The log you provided shows only two commands, both of which completed 
successfully.  Is that really the place where things got hung?  If it is 
then the problem isn't in the USB stack but someplace higher up: the SCSI 
stack, the block layer, or the filesystem layer.

Alan Stern

Re: [linux-usb-devel] Re: BUG: 2.6.14/2.6.15: USB storage/ext2fs uninterruptable sleep

[Roger Leigh]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Alan Stern <stern@rowland.harvard.edu> writes:

> On Thu, 5 Jan 2006, Roger Leigh wrote:
>
>> > By any chance, does autofs or autofs4 mount your device with -o sync?  
>> > Doing that with flash memory devices is a grave mistake -- although it 
>> > shouldn't cause the sort of lock-up you described.
>> 
>> Yes.  I have
>> 
>> pen-secure  -fstype=ext2,sync,nodev,nosuid,noatime  :/dev/sda2
>> 
>> in /etc/auto.misc.  Removing the sync option does prevent the lockups.
>> I just added it back and it locked up immediately.
>
> Sync for flash devices is generally a bad idea.  Especially with vfat 
> filesystems but to some extent with all of them, it causes constant 
> rewriting of sectors containing metadata.  Flash memory behaves poorly 
> when the same sector gets written over and over again; it tends to slow 
> down and eventually wear out completely.

ACK.  The device is generally only used for reading, and I wanted it
to be safe for accidental unplugging soon after a write (hence the
reason I didn't spot it in 2.6.14: I hadn't written to it for six
months!).  It's also supposed to do write-levelling, though I don't
know how good it is.

>> The usb/usb-storage logs are attached (device mount + command which
>> broke it).  Would you like any more information?
>
> The log you provided shows only two commands, both of which completed 
> successfully.  Is that really the place where things got hung?

Yes.  I confirmed this with the kern.log timestamps.  The log might
exclude the mount (it might be a chdir instead), but definitely
includes the failure, since there were no further writes to the log
for at least five minutes after the hang, with no further USB
messages.  BTW, after the hangs I could still copy the file in
question, and also create/delete other files on the same filesystem,
so it was not entirely dead, just wedged on that one thing.

> If it is then the problem isn't in the USB stack but someplace
> higher up: the SCSI stack, the block layer, or the filesystem layer.

Yikes.


Regards,
Roger

- -- 
Roger Leigh
                Printing on GNU/Linux?  http://gimp-print.sourceforge.net/
                Debian GNU/Linux        http://www.debian.org/
                GPG Public Key: 0x25BFB848.  Please sign and encrypt your mail.
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.2 (GNU/Linux)
Comment: Processed by Mailcrypt 3.5.8+ <http://mailcrypt.sourceforge.net/>

iD8DBQFDvXM9VcFcaSW/uEgRAjJuAKDsfJtTwOhyuzopsR+M8yxU+3lgjgCfS1jb
CabRaCer49elckXQmrKDKVY=
=9891
-----END PGP SIGNATURE-----