Messages in this thread | | | From | Monty <> | Subject | Got it! SG select() bug evidence for 2.2.2 | Date | Fri, 19 Mar 1999 04:19:51 EST |
| |
I'll say this first because I know most won't read much of this...:
If you've seen the following output from cdparanoia, MAIL ME!!:
"SCSI transport: writeable when reading packet"
The above message indicates you've probably tripped a kernel bug that shows up only very rarely, and I need to know more about that bug!
Now, on to the part I want Doug, Jens, Joerg and the bughunter hordes to read:
I've finally found hard evidence of a bug in 2.2.x [at least manifested] in SG. It's possible this has been fixed in dougg's and joerg's recent drivers (it took a long time to find hard proof/documentation of this problem, and the machine is remote; I'm leading the user through debugging now), but the nature of the bug leads me to believe I should report it because I'm only 80% certain it's SG.
I'm throwing this open to others now because after sleepless nights with the kernel source, I honestly can't say how the below report is possible even under the strangest conditions; given that I can't find even a remote explanation of the problem and that I've only seen two reports (only one with enough documentation) I doubt this has been fixed unless accidently. OTOH, I'm honestly hoping Joerg or Doug is going to say "oh, yeah, *that* bug. It's fixed." so I can stop worrying :-)
The story thus-far in chronological order:
In cdparanoia when I'm doing SCSI commands, rather than just doing 'write()' and then immediately blocking on the following 'read()', I select() for readable before read()ing. On a lark, in alpha 9.4 I also decided to return from select() if the SG device's fd ever went writable rather than readable. From looking at the SG code I didn't think it would happen, but a test costs nothing so I put it in.
What is happening on just two machines is much weirder than I expected could be possible. The SG device fd is in fact immediately returning 'writable' from a select() call immediately after successfully writing a packet to SG; from reading the kernel source, I see absolutely no way this is possible, and on the two machines in question, the behavior is apparently 100% reproducable on at least one device (eg, every SG command written does this, causing cdparanoia to fail instantly. No SG commands succeed; all end up indicating 'writable' immediately after writing the packet. One user also reported that the command occasionally just hangs, never returning readable or writable, and occasionally returns 'writable').
I gave the users in question a patch to paranoia to ignore the fd indicating writable and wait for readable status from select(); SG commands suddenly work with no errors. I have not yet given code that logs for certain whether or not the fd first select()s writable and then upon a subsequent select() indicates readable; all I know is that on these machines, giving select() a readable fd_set only works, but when passing the same fd in the both a read and write fd_set to select(), writeable status is returned (which, as I'm beating into the ground, seems impossible from reading the kernel source).
The two machines for which I have documented evidence of the bug are running 2.2.2 and 2.2.3. The description of the problem matches behavior that was first reported to me by users in late 2.1 (before the release of a paranoia version with this check). Note that I do not have documented evidence that this is the same bug as appeared to happen earlier in 2.1; it could be a coincidence. However, the late 2.1 SG driver did see the select() infrastructure replaced with poll()...
I'm bringing this up despite the newer drivers because from looking at the 2.2 SG, I don't see how it could be making this mistake--- and thus I'm worried it could be select(). I have a patch out to the user that will test exactly this theory and I'll report back as soon as I know. I'm also sending him Doug's and Joerg's newest SGs to try.
I have an strace below that shows that the fd is indeed becoming writable after successfully write()ing a SCSI packet to SG. I'm in the process of gathering more debugging information from the user, but the machine is remote and disconnected from the net, so debugging must happen through email exchanges.
Note that despite my interjections, all the straces lines are unedited and in order:
>open("/dev/sg3", O_RDWR|O_EXCL) = 4
The SG device is fd 4
>stat("/dev/scd0", {st_mode=S_ISUID|S_ISVTX|0400, st_size=0, ...}) = 0 >brk(0x807e000) = 0x807e000 >ioctl(3, CDROMAUDIOBUFSIZ, 0xbffff51c) = 0
strace is reporting a different ioctl() name here that uses the same number. this is actually SCSI_IOCTL_GET_IDLUN
>ioctl(3, 0x5386, 0xbffff518) = 0
..and SCSI_IOCTL_GET_BUS_NUMBER
>select(5, [4], NULL, NULL, {0, 0}) = 0 (Timeout)
going into handle_command, the fresh SG fd has no data to be read back, as expected.
>select(5, NULL, [4], NULL, {5, 0}) = 1 (out [4], left {5, 0})
ready to write a packet command, as expected...
>sigprocmask(SIG_BLOCK, [INT PIPE TERM PROF], NULL) = 0
Block SIGINT, etc... closing an SG fd with a command outstanding is a great way to 'oops'.
>write(4, "\0\0\0\0\\\0\0\0\0\0\0\0\0\0\0\0"..., 98) = 98
The packet command write succeeds. device->pending is set to 1.
>select(5, [4], [4], [4], {15, 0}) = 1 (out [4], left {15, 0})
!!! the select returns only one fd and it's in the writable fd_set! This should only be possible if device->pending is zero. There are no intervening operations that could unset it (eg, close, read, etc).
>write(2, "\nSCSI transport: writeable when"..., 48 >SCSI transport: writeable when reading packet
Death and taxes.
Any explanations? I'm stumped (for now).
Monty
- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.rutgers.edu Please read the FAQ at http://www.tux.org/lkml/
| |