Re: Slow USB storage device?

[Linus Torvalds <torvalds@xxxxxxxxxxxxxxxxxxxx>]

[ Moving Alan Stern and Greg to the cc, this seems to not be an USB issue 
  as much as a blkid and udev thing.  So I added util-linux-ng and Karel 
  and Kay to the recipients list..

  Background: I have a _really_ slow USB disk-like device. Or more 
  properly, my wife does - it's an embroidery machine that has a USB 
  storage interface. And the thing gets about 16kB/s.

  Yes. 16 _kB_ per second. Not MB. Which is actually perfectly fine, since 
  the designs you upload to it are generally in the 20kB range. Who cares 
  how fast or slow it is?

  Except it takes about half a minute to show up as a disk, because udev 
  and blkid take _forever_, and try to read a hell of a lot more than 
  they should. Can somebody please fix this? ]

On Thu, 14 Jan 2010, Linus Torvalds wrote:
> 
> Right you are. dmesg shows /dev/sdc1, but udev hasn't actually created the 
> file yet. 

Yeah, and it is indeed waiting for blkid (and then later apparently 
hald-probe-volume). I had stupidly thought that udev would create the 
trivial device names that don't need any translation immediately. Not so.

> I've seen it with two very different computers, so I don't think that's 
> it. But I did use the same cable etc, so who knows..

Tried a third computer, and different cable. Same deal. Except now your 
hint made me look at what's going on, and it is indeed all waiting for 
some ID that will never give any interesting results.

On a Fedora-12 machine, it's /sbin/blkid, on an older setup it seems to be 
/lib/udev/vol_id like Alan said.

And it really is the same speed on all computers, so it's simply that the 
hardware really is that slow. 16kB/s.

> > Probably they are caused by udev and hal.  Those packages each include
> > a program that scans new drives and partitions looking for volume IDs:
> > 
> > 	/lib/udev/vol_id
> > 	/usr/libexec/hald-probe-{volume or storage, I forget which}
> 
> Will try. Will also double-check with a third computer and a different 
> cable, just in case.

Well, I can make those go away, and then the device shows up largely 
immediately. However, then I still don't get the automagic mount, so it 
looks like the fundamental problem is how blkid/vol_id is really slow, and 
after being really slow it still doesn't actually get any ID.

On that machine, with the embroidery machine plugged in:

	[root@EeePC torvalds]# time blkid -o udev -p /dev/sdc
	
	real	0m13.736s
	user	0m0.002s
	sys	0m0.007s

and:

	[root@EeePC torvalds]# time blkid -o udev -p /dev/sdc1
	ID_FS_SEC_TYPE=msdos
	ID_FS_VERSION=FAT12
	ID_FS_TYPE=vfat
	ID_FS_USAGE=filesystem
	
	real	0m13.491s
	user	0m0.003s
	sys	0m0.005s

ie it took a total of 27s+ to just do blkid on first the whole disk (which 
had nothing on it, of course), and then the first partition (which just 
has an empty FAT filesystem on it).

Half a minute to figure out something like that, and then it doesn't even 
mount anything, apparently because it has no UUID!

The reason is almost purely that it does this:

	15:51:05.466494 _llseek(3, 0, [0], SEEK_SET) = 0 <0.000107>
	15:51:05.466930 read(3, ""..., 69632) = 69632 <8.186289>

ie it does that one large read (which is indeed big enough that the kernel 
will start read-ahead, so the 68kB read turns into a 120kB one)

There's a few other ones that are in the "just under a second" range 
because this thing is a really slow disk, but that one read obviously 
accounts for 60% of it all.

After it has done the blkid on both devices, it then also does

	/lib/udev/devkit-disks-part-id /dev/.tmp-block-8:33

which takes an additional second, and results in

	Entering MS-DOS parser (offset=0, size=505856)
	MSDOS_MAGIC found
	looking at part 0 (offset 16384, size 505344, type 0x01)
	new part entry
	looking at part 1 (offset 0, size 0, type 0x00)
	new part entry
	looking at part 2 (offset 0, size 0, type 0x00)
	new part entry
	looking at part 3 (offset 0, size 0, type 0x00)
	new part entry
	Exiting MS-DOS parser
	MSDOS partition table detected
	DKD_PARTITION=1
	DKD_PARTITION_SCHEME=mbr
	DKD_PARTITION_NUMBER=1
	DKD_PARTITION_TYPE=0x01
	DKD_PARTITION_SIZE=505344
	DKD_PARTITION_LABEL=
	DKD_PARTITION_UUID=
	DKD_PARTITION_FLAGS=boot

so that udev tool gets all the same information, and does it _much_ 
faster.

So a few questions:

 - can we please not use 'blkid' at all in udev? It looks like the udev 
   native 'devkit-disks-part-id' is much better at this, and since udev 
   does it _anyway_ afterwards, how about doing it up-front instead?

 - maybe blkid could be improved to not be such a pig. Even if you don't 
   have a really slow device like mine, I bet people could see some of the 
   same issues with a USB floppy drive.

 - Why do we try to even identify /dev/sdc, when the kernel has already 
   partitioned it and we'd be much better identifying just the partition?

 - What am I supposed to do with a disk that has no UUID? It doesn't get 
   mounted by hald at all. That kind of sucks. I'd like to see the 
   filesystem, despite it not having an ID. Or maybe it doesn't get 
   mounted for some other reason (I thought it was just because everything 
   was so slow and the disk read failed when it tried to mount things, but 
   since this is all driven by udev anyway, I'm now assuming that that 
   wasn't the case, and it's the missing uuid)

And no, I can't just add a UUID to the thing. It's a piece of external 
hardware with odd firmware that I don't control.

			Linus
--
To unsubscribe from this list: send the line "unsubscribe util-linux-ng" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html