I (very recently) purchased a Teac CD-W524E drive. Unfortunately, it does not seem to be very compatible with pktcdvd. To be specific, it is EXTREMELY slow (ls on a relatively small directory once took five minutes; writing 150 megabytes to the disc and umounting it took over an hour!) and the discs seem to be highly prone to spontaneous corruption (for instance, an attempt at an ls of a file that should be there results in "permission denied" errors). IDE and SCSI emulation modes produced no difference in results that I could detect. Following is an excerpt from the log from a typical write. Notice the five minute delay towards the end. I didn't include the whole log excerpt because the operation generated about 8 megabytes of logging info. :) I did notice the log comments were very different than those left by the Sony CRX175A, which I managed to get to operate successfully. If anyone could help me with this, I'd appreciate it. I'd like Mount Rainier support on a drive, and Teac supposedly has it, but if I can't get it to work on Linux I'll have to take it back in about ten days to get my money back. Any help you can give me would be greatly appreciated. If it matters, I am running kernel 2.4.17. Jan 13 19:49:48 darkstar kernel: unlocked last 699772 Jan 13 19:49:48 darkstar kernel: __pkt_inject_request: list_empty == 1, size=4, cmd=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174912, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174913, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174914, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174915, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174916, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174917, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174918, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=37077102, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174920, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174921, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174922, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174923, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174924, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174925, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174926, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174927, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174928, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174929, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174930, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174931, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174932, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174933, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174934, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174935, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174936, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174937, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174938, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174939, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174940, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174941, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174942, uptodate=1 Jan 13 19:49:48 darkstar kernel: end_io_write: bh=174943, uptodate=1 Jan 13 19:49:48 darkstar kernel: pkt_rq_end_io: rq=ce5ecf00, cmd=1, q=00000000 Jan 13 19:49:48 darkstar kernel: handle_queue Jan 13 19:49:48 darkstar kernel: pkt_request: cmd=1, rq=ce5eb200, rq->sector=700020, rq->nr_sectors=4 Jan 13 19:49:48 darkstar kernel: wake up wait queue Jan 13 19:49:48 darkstar kernel: handle_queue Jan 13 19:49:48 darkstar kernel: do_request: bh=37077101, nr_sectors=4, size=128, cmd=1 Jan 13 19:49:48 darkstar kernel: pkt_gather_data: cmd=1 Jan 13 19:49:48 darkstar kernel: need 124 sectors for 0b:01 Jan 13 19:49:48 darkstar kernel: from 699904 to 700032 <5>(700020 - 700024) Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699904, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699908, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699912, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699916, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699920, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699924, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699928, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699932, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699936, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699940, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699944, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699948, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699952, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699956, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699960, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699964, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699968, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699972, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699976, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699980, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699984, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699988, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699992, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=699996, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=700000, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=700004, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=700008, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=700012, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=700016, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=700024, size=2048 Jan 13 19:49:48 darkstar kernel: get_buffer: sector=700028, size=2048 Jan 13 19:56:27 darkstar kernel: unlocked last 700028 Jan 13 19:56:27 darkstar kernel: __pkt_inject_request: list_empty == 1, size=4, cmd=1 __________________________________________________ Do You Yahoo!? Send FREE video emails in Yahoo! Mail! http://promo.yahoo.com/videomail/
I'm trying to get packet writing working with a HP 8230e CDWriter, connecting via USB. Running cdrwtool to prepare the CD, I get: =========================================================== #cdrwtool -d /dev/sr1 -t 4 -q using device /dev/sr1 setting speed to 4 cdrom: This disc doesn't have any tracks I recognize! 4085KB internal buffer setting write speed to 4x Settings for /dev/sr1: Fixed packets, size 32 Mode-2 disc I'm going to do a quick setup of /dev/sr1. The disc is going to be blanked and formatted with one big track. All data on the device will be lost!! Press CTRL-C to cancel now. Initiating quick disc blank Disc capacity is 275744 blocks (551488KB/538MB) Formatting track =========================================================== and there it gets stuck, at "Formatting track". I switched on verbose debug messages for the usb-storage module, which tells me (/var/log/syslog): Jan 17 02:37:28 strider kernel: usb-storage: *** thread awakened. Jan 17 02:37:28 strider kernel: usb-storage: Command MODE_SENSE_10 (10 bytes) Jan 17 02:37:28 strider kernel: usb-storage: 5a 00 85 00 00 00 00 00 3c 00 00 00 Jan 17 02:37:28 strider kernel: usb-storage: Status = 50 Jan 17 02:37:28 strider kernel: usb-storage: Transferred out 14 of 14 bytes Jan 17 02:37:28 strider kernel: usb-storage: Waited not busy for 0 steps Jan 17 02:37:28 strider kernel: usb-storage: Transferred out 12 of 12 bytes Jan 17 02:37:28 strider kernel: usb-storage: Waited not busy for 0 steps Jan 17 02:37:28 strider kernel: usb-storage: Transferred in 60 of 60 bytes Jan 17 02:37:28 strider kernel: usb-storage: 00 3A 21 00 00 00 00 00 05 32 00 E7 0A 00 00 00 Jan 17 02:37:28 strider kernel: usb-storage: 20 00 00 00 00 20 00 96 00 00 00 00 00 00 00 00 Jan 17 02:37:28 strider kernel: usb-storage: scsi cmd done, result=0x0 Jan 17 02:37:28 strider kernel: usb-storage: *** thread sleeping. Jan 17 02:37:28 strider kernel: usb-storage: queuecommand() called Jan 17 02:37:28 strider kernel: usb-storage: *** thread awakened. Jan 17 02:37:28 strider kernel: usb-storage: Command MODE_SELECT_10 (10 bytes) Jan 17 02:37:28 strider kernel: usb-storage: 55 10 00 00 00 00 00 00 3c 00 00 00 Jan 17 02:37:28 strider kernel: usb-storage: Status = 50 Jan 17 02:37:28 strider kernel: usb-storage: Transferred out 38 of 38 bytes Jan 17 02:37:28 strider kernel: usb-storage: Transferred out 60 of 60 bytes Jan 17 02:37:28 strider kernel: usb-storage: Waited not busy for 1 steps Jan 17 02:37:28 strider kernel: usb-storage: Wrote 0000003C bytes Jan 17 02:37:28 strider kernel: usb-storage: scsi cmd done, result=0x0 Jan 17 02:37:28 strider kernel: usb-storage: *** thread sleeping. Jan 17 02:37:35 strider kernel: usb-storage: queuecommand() called Jan 17 02:37:35 strider kernel: usb-storage: *** thread awakened. Jan 17 02:37:35 strider kernel: usb-storage: Command BLANK (12 bytes) Jan 17 02:37:35 strider kernel: usb-storage: a1 01 00 00 00 00 00 00 00 00 00 00 Jan 17 02:37:35 strider kernel: usb-storage: Status = 50 Jan 17 02:37:35 strider kernel: usb-storage: Transferred out 14 of 14 bytes Jan 17 02:37:35 strider kernel: usb-storage: Waited not busy for 0 steps Jan 17 02:37:35 strider kernel: usb-storage: Transferred out 12 of 12 bytes Jan 17 02:39:13 strider kernel: usb-storage: Waited not busy for 1220 steps Jan 17 02:39:13 strider kernel: usb-storage: scsi cmd done, result=0x0 Jan 17 02:39:13 strider kernel: usb-storage: *** thread sleeping. Jan 17 02:39:13 strider kernel: usb-storage: queuecommand() called Jan 17 02:39:13 strider kernel: usb-storage: *** thread awakened. Jan 17 02:39:13 strider kernel: usb-storage: Command READ TRACK INFORMATION (10 bytes) Jan 17 02:39:13 strider kernel: usb-storage: 52 01 00 00 00 01 00 00 1c 00 00 00 Jan 17 02:39:13 strider kernel: usb-storage: Status = 50 Jan 17 02:39:13 strider kernel: usb-storage: Transferred out 14 of 14 bytes Jan 17 02:39:13 strider kernel: usb-storage: Waited not busy for 0 steps Jan 17 02:39:13 strider kernel: usb-storage: Transferred out 12 of 12 bytes Jan 17 02:39:13 strider kernel: usb-storage: Waited not busy for 1 steps Jan 17 02:39:13 strider kernel: usb-storage: Transferred in 28 of 28 bytes Jan 17 02:39:13 strider kernel: usb-storage: 00 1A 01 01 00 05 72 01 00 00 00 00 00 00 00 00 Jan 17 02:39:13 strider kernel: usb-storage: 00 04 35 20 00 00 00 20 00 04 35 20 Jan 17 02:39:13 strider kernel: usb-storage: scsi cmd done, result=0x0 Jan 17 02:39:13 strider kernel: usb-storage: *** thread sleeping. Jan 17 02:39:13 strider kernel: usb-storage: queuecommand() called Jan 17 02:39:13 strider kernel: usb-storage: *** thread awakened. Jan 17 02:39:13 strider kernel: usb-storage: Command FORMAT_UNIT (6 bytes) Jan 17 02:39:13 strider kernel: usb-storage: 04 17 00 00 00 00 00 00 00 00 00 00 Jan 17 02:39:13 strider kernel: usb-storage: Status = 50 Jan 17 02:39:13 strider kernel: usb-storage: Transferred out 38 of 38 bytes Jan 17 02:39:13 strider kernel: usb-storage: Transferred out 16 of 16 bytes Jan 17 02:50:37 strider kernel: usb-storage: Waited not busy for 10 minutes, timing out. Jan 17 02:50:37 strider kernel: usb-storage: -- transport indicates command failure Jan 17 02:50:37 strider kernel: usb-storage: Issuing auto-REQUEST_SENSE Jan 17 02:50:37 strider kernel: usb-storage: Status = D0 Jan 17 02:50:37 strider kernel: usb-storage: Transferred out 14 of 14 bytes Jan 17 02:51:54 strider kernel: usb-storage: Waited not busy for 0 minutes, timing out. Jan 17 02:51:54 strider kernel: usb-storage: -- auto-sense failure Jan 17 02:51:54 strider kernel: usb-storage: CB_reset() called Jan 17 02:51:59 strider kernel: usb_control/bulk_msg: timeout Jan 17 02:51:59 strider kernel: usb-storage: CB[I] soft reset failed -110 Jan 17 02:51:59 strider kernel: usb-storage: scsi cmd done, result=0x70000 Jan 17 02:51:59 strider kernel: usb-storage: *** thread sleeping. Jan 17 02:51:59 strider kernel: usb-storage: queuecommand() called Jan 17 02:51:59 strider kernel: usb-storage: *** thread awakened. Jan 17 02:51:59 strider kernel: usb-storage: Command FORMAT_UNIT (6 bytes) Jan 17 02:51:59 strider kernel: usb-storage: 04 17 00 00 00 00 00 00 00 00 00 00 Jan 17 02:51:59 strider kernel: usb-storage: Status = D0 Jan 17 02:51:59 strider kernel: usb-storage: Transferred out 38 of 38 bytes Jan 17 02:51:59 strider kernel: usb-storage: Transferred out 16 of 16 bytes Jan 17 03:03:22 strider kernel: usb-storage: Waited not busy for 10 minutes, timing out. Jan 17 03:03:22 strider kernel: usb-storage: -- transport indicates command failure Jan 17 03:03:22 strider kernel: usb-storage: Issuing auto-REQUEST_SENSE Jan 17 03:03:22 strider kernel: usb-storage: Status = D0 I can see the BLANK and READ TRACK INFORMATION commands, apparently successful, but it appears to be timing out while running the FORMAT_UNIT command in the usb subsystem. Is there anything I can do to get a more successful result? Drew Parsons -- PGP public key available at http://people.debian.org/~dparsons/drewskey.txt Fingerprint: A110 EAE1 D7D2 8076 5FE0 EC0A B6CE 7041 6412 4E4A
On Thu, Jan 17, 2002 at 03:15:48AM +1100, Drew Parsons wrote:
I can see the BLANK and READ TRACK INFORMATION commands, apparently successful, but it appears to be timing out while running the FORMAT_UNIT command in the usb subsystem.
Well, I've seen FORMAT_UNIT's on a full CDRW take over an hour, so 10 minutes is definitely not enough time =) Theoretically, a timeout is passed to the command.. I'd check to see if USB ever looks at the timeout.. Ben
On Wed, Jan 16, 2002 at 12:45:12PM -0800, Ben Fennema wrote:
On Thu, Jan 17, 2002 at 03:15:48AM +1100, Drew Parsons wrote:
I can see the BLANK and READ TRACK INFORMATION commands, apparently successful, but it appears to be timing out while running the FORMAT_UNIT command in the usb subsystem.
Well, I've seen FORMAT_UNIT's on a full CDRW take over an hour, so 10 minutes is definitely not enough time =)
Theoretically, a timeout is passed to the command.. I'd check to see if USB ever looks at the timeout..
Ben
The relevant piece of coding, corresponding to the log message: Jan 17 03:03:22 strider kernel: usb-storage: Waited not busy for 10 minutes= , timing out. comes from linux/drivers/usb/storage/shuttle_usbat.c, in function int usbat_wait_not_busy(struct us_data *us, int minutes). The minutes argument provides the "10" in the 10 minute timeout. The comments there say /* Synchronizing cache on a CDR could take a heck of a long time, * but probably not more than 10 minutes or so. On the other hand, * doing a full blank on a CDRW at speed 1 will take about 75 * minutes! */ The function has a loop, pausing between iterations with wait_ms(1000), which checks usbat_read(). The result of usbat_read() may indicates a good or bad access, but if it says neither, the timeout is eventually reached. The value of 10 (minutes) appears to be defined (hardcoded) while processing (srb->sc_data_direction == SCSI_DATA_WRITE) in hp8200e_transport(). Elsewhere in shuttle_usbat.c, a value of 1 (or 0) is used. It's also conditionally defined in hp8200e_transport() while processing any command: // Write the 12-byte command header. // If the command is BLANK then set the timer for 75 minutes. // Otherwise set it for 10 minutes. // NOTE: THE 8200 DOCUMENTATION STATES THAT BLANKING A CDRW // AT SPEED 4 IS UNRELIABLE!!! if ( (result = usbat_write_block(us, USBAT_ATA, 0x10, srb->cmnd, 12, 0, srb->cmnd[0]==GPCMD_BLANK ? 75 : 10)) != USB_STOR_TRANSPORT_GOOD) { return result; } My gut feeling is this is the source of the "10 minutes" that I'm timing out on. Would it therefore make sense to test for FORMAT_UNIT alongside the current test for GPCMD_BLANK, making the timeout 75 minutes for FORMAT_UNIT ? Does anyone have any other deep wisdom or insight to tell about this? Thanks, Drew -- PGP public key available at http://people.debian.org/~dparsons/drewskey.txt Fingerprint: A110 EAE1 D7D2 8076 5FE0 EC0A B6CE 7041 6412 4E4A
On Wed, Jan 23, 2002 at 10:21:25PM +1100, Drew Parsons wrote:
It's also conditionally defined in hp8200e_transport() while processing any command: // Write the 12-byte command header.
// If the command is BLANK then set the timer for 75 minutes. // Otherwise set it for 10 minutes.
// NOTE: THE 8200 DOCUMENTATION STATES THAT BLANKING A CDRW // AT SPEED 4 IS UNRELIABLE!!!
if ( (result = usbat_write_block(us, USBAT_ATA, 0x10, srb->cmnd, 12, 0, srb->cmnd[0]==GPCMD_BLANK ? 75 : 10)) != USB_STOR_TRANSPORT_GOOD) { return result; } My gut feeling is this is the source of the "10 minutes" that I'm timing out on.
Would it therefore make sense to test for FORMAT_UNIT alongside the current test for GPCMD_BLANK, making the timeout 75 minutes for FORMAT_UNIT ?
Ya, something like: if ( (result = usbat_write_block(us, USBAT_ATA, 0x10, srb->cmnd, 12, 0, (srb->cmnd[0]==GPCMD_BLANK||srb->cmnd[0]==GPCMD_FORMAT_UNIT) ? 75 : 10)) != USB_STOR_TRANSPORT_GOOD) { return result; } Ben
On Wed, Jan 23, 2002 at 11:26:31AM -0800, Ben Fennema wrote:
On Wed, Jan 23, 2002 at 10:21:25PM +1100, Drew Parsons wrote:
It's also conditionally defined in hp8200e_transport() while processing any command: if ( (result = usbat_write_block(us, USBAT_ATA, 0x10, srb->cmnd, 12, 0, srb->cmnd[0]==GPCMD_BLANK ? 75 : 10)) != USB_STOR_TRANSPORT_GOOD) { return result; }
Would it therefore make sense to test for FORMAT_UNIT alongside the current test for GPCMD_BLANK, making the timeout 75 minutes for FORMAT_UNIT ?
Ya, something like:
if ( (result = usbat_write_block(us, USBAT_ATA, 0x10, srb->cmnd, 12, 0, (srb->cmnd[0]==GPCMD_BLANK||srb->cmnd[0]==GPCMD_FORMAT_UNIT) ? 75 : 10)) != USB_STOR_TRANSPORT_GOOD) { return result; }
I was going to say that should be FORMAT_UNIT not GPCMD_FORMAT_UNIT, but it seems you're prefectly correct :) FORMAT_UNIT is a scsi code from include/scsi/scsi.h, while GPCMD_FORMAT_UNIT is a generic packet command (from include/linux/cdrom/h), although the actual values seem the same for equivalent commands. I put some extra debug code to see what the actual commands were. Command BLANK, for example, is 0xa1, which isn't present in scsi.h but is GPCMD_BLANK in cdrom.h. Curiously, I couldn't find command READ BUFFER CAPACITY (0x5c) in either cdrom.h or scsi.h, although it appeared in the log, but all other commands were in the include files. But my debug messages also showed that this call to usbat_write_block() is not where FORMAT_UNIT is taking place. It's happening a bit higher in hp8200e_transport() (in usb/storage/shuttle_usbat.c), at if (srb->sc_data_direction == SCSI_DATA_WRITE) { result = usbat_rw_block_test(us, USBAT_ATA, registers, data, 19, 0x10, 0x17, 0xFD, 0x30, SCSI_DATA_WRITE, srb->request_buffer, len, srb->use_sg, 10); ... } So I'll try changing this 10 to 75, and report back when I'm done. Drew -- PGP public key available at http://people.debian.org/~dparsons/drewskey.txt Fingerprint: A110 EAE1 D7D2 8076 5FE0 EC0A B6CE 7041 6412 4E4A
On Sat, Feb 02, 2002 at 08:52:05AM +1100, Drew Parsons wrote:
But my debug messages also showed that this call to usbat_write_block() is not where FORMAT_UNIT is taking place. It's happening a bit higher in hp8200e_transport() (in usb/storage/shuttle_usbat.c), at
if (srb->sc_data_direction == SCSI_DATA_WRITE) { result = usbat_rw_block_test(us, USBAT_ATA, registers, data, 19, 0x10, 0x17, 0xFD, 0x30, SCSI_DATA_WRITE, srb->request_buffer, len, srb->use_sg, 10); .... }
So I'll try changing this 10 to 75, and report back when I'm done.
I tried this change, it seems to work. Formatting completed, taking about 40 minutes, but another problem came up while creating the UDF file system: ====================================== # cdrwtool -d /dev/sr1 -t 4 -q using device /dev/sr1 setting speed to 4 4085KB internal buffer setting write speed to 4x Settings for /dev/sr1: Fixed packets, size 32 Mode-2 disc I'm going to do a quick setup of /dev/sr1. The disc is going to be blanked and formatted with one big track. All data on the device will be lost!! Press CTRL-C to cancel now. Initiating quick disc blank Disc capacity is 275744 blocks (551488KB/538MB) Formatting track Writing UDF structures to disc 39600 (EST)/-660 wait_cmd: Invalid argument Command failed: 2a 00 00 00 01 00 00 00 20 00 00 00 - sense 05.24.00 Error writing packet 8 (ffffffff) =========================================== The log showed, starting from the FORMAT_UNIT command: ... Feb 2 09:29:22 strider kernel: usb-storage: queuecommand() called Feb 2 09:29:22 strider kernel: usb-storage: *** thread awakened. Feb 2 09:29:22 strider kernel: usb-storage: Command FORMAT_UNIT (6 bytes) Feb 2 09:29:22 strider kernel: usb-storage: 04 17 00 00 00 00 00 00 00 00 00 00 Feb 2 09:29:22 strider kernel: usb-storage: Status = 50 Feb 2 09:29:22 strider kernel: usb-storage: In hp8200e_transport() before usb_rw_block_test() for SCSI_DATA_WRITE. Feb 2 09:29:22 strider kernel: usb-storage: Transferred out 38 of 38 bytes Feb 2 09:29:22 strider kernel: usb-storage: Transferred out 16 of 16 bytes Feb 2 09:29:22 strider kernel: usb-storage: In usbat_wait_not_busy(), waiting for 75 minutes. Feb 2 10:08:45 strider kernel: usb-storage: Waited not busy for 3462 steps Feb 2 10:08:45 strider kernel: usb-storage: In hp8200e_transport(), usb_rw_block_test() complete with result=0. Feb 2 10:08:45 strider kernel: usb-storage: Wrote 0000004C bytes Feb 2 10:08:45 strider kernel: usb-storage: scsi cmd done, result=0x0 Feb 2 10:08:45 strider kernel: usb-storage: *** thread sleeping. Feb 2 10:08:45 strider kernel: usb-storage: queuecommand() called Feb 2 10:08:45 strider kernel: usb-storage: *** thread awakened. Feb 2 10:08:45 strider kernel: usb-storage: Command WRITE_10 (10 bytes) Feb 2 10:08:45 strider kernel: usb-storage: 2a 00 00 00 00 00 00 00 20 00 00 00 Feb 2 10:08:45 strider kernel: usb-storage: Status = 50 Feb 2 10:08:45 strider kernel: usb-storage: In hp8200e_transport() before usb_rw_block_test() for SCSI_DATA_WRITE. Feb 2 10:08:45 strider kernel: usb-storage: Transferred out 38 of 38 bytes Feb 2 10:08:45 strider kernel: usb-storage: In usbat_wait_not_busy(), waiting for 75 minutes. Feb 2 10:08:45 strider kernel: usb-storage: Waited not busy for 1 steps Feb 2 10:08:45 strider kernel: usb-storage: In hp8200e_transport(), usb_rw_block_test() complete with result=0. Feb 2 10:08:45 strider kernel: usb-storage: Wrote 0001004C bytes Feb 2 10:08:45 strider kernel: usb-storage: scsi cmd done, result=0x0 Feb 2 10:08:45 strider kernel: usb-storage: *** thread sleeping. Feb 2 10:08:45 strider kernel: usb-storage: queuecommand() called Feb 2 10:08:45 strider kernel: usb-storage: *** thread awakened. Feb 2 10:08:45 strider kernel: usb-storage: Command WRITE_10 (10 bytes) Feb 2 10:08:45 strider kernel: usb-storage: 2a 00 00 00 01 00 00 00 20 00 00 00 Feb 2 10:08:45 strider kernel: usb-storage: Status = 58 Feb 2 10:08:45 strider kernel: usb-storage: In hp8200e_transport() before usb_rw_block_test() for SCSI_DATA_WRITE. Feb 2 10:08:45 strider kernel: usb-storage: Transferred out 38 of 38 bytes Feb 2 10:08:45 strider kernel: usb-storage: In usbat_wait_not_busy(), waiting for 75 minutes. Feb 2 10:08:45 strider kernel: usb-storage: In hp8200e_transport(), usb_rw_block_test() complete with result=1. Feb 2 10:08:45 strider kernel: usb-storage: -- transport indicates command failure Feb 2 10:08:45 strider kernel: usb-storage: Issuing auto-REQUEST_SENSE Feb 2 10:08:45 strider kernel: usb-storage: Status = 00 Feb 2 10:08:45 strider kernel: usb-storage: Transferred out 14 of 14 bytes Feb 2 10:08:45 strider kernel: usb-storage: In usbat_wait_not_busy(), waiting for 0 minutes. Feb 2 10:08:45 strider kernel: usb-storage: Waited not busy for 0 steps Feb 2 10:08:45 strider kernel: usb-storage: In hp8200e_transport() before usb_write_block(), cmnd = 0x3. Feb 2 10:08:45 strider kernel: usb-storage: Transferred out 12 of 12 bytes Feb 2 10:08:45 strider kernel: usb-storage: In usbat_wait_not_busy(), waiting for 10 minutes. Feb 2 10:08:45 strider kernel: usb-storage: Waited not busy for 0 steps Feb 2 10:08:45 strider kernel: usb-storage: Transferred in 18 of 18 bytes Feb 2 10:08:45 strider kernel: usb-storage: 70 00 05 00 00 00 00 12 00 00 00 00 24 00 00 C0 Feb 2 10:08:45 strider kernel: usb-storage: 00 02 Feb 2 10:08:45 strider kernel: usb-storage: -- Result from auto-sense is 0 Feb 2 10:08:45 strider kernel: usb-storage: -- code: 0x70, key: 0x5, ASC: 0x24, ASCQ: 0x0 Feb 2 10:08:45 strider kernel: usb-storage: Illegal Request: invalid field in CDB Feb 2 10:08:45 strider kernel: usb-storage: scsi cmd done, result=0x2 Feb 2 10:08:45 strider kernel: usb-storage: *** thread sleeping. Feb 2 10:08:45 strider kernel: sr1: CDROM (ioctl) reports ILLEGAL REQUEST. Feb 2 10:08:45 strider kernel: usb-storage: queuecommand() called Feb 2 10:08:45 strider kernel: usb-storage: *** thread awakened. Feb 2 10:08:45 strider kernel: usb-storage: Command ALLOW_MEDIUM_REMOVAL (6 bytes) Feb 2 10:08:45 strider kernel: usb-storage: 1e 00 00 00 00 00 ff ff e0 f9 89 c3 Feb 2 10:08:45 strider kernel: usb-storage: Status = 50 Feb 2 10:08:45 strider kernel: usb-storage: Transferred out 14 of 14 bytes Feb 2 10:08:45 strider kernel: usb-storage: In usbat_wait_not_busy(), waiting for 0 minutes. Feb 2 10:08:45 strider kernel: usb-storage: Waited not busy for 0 steps Feb 2 10:08:45 strider kernel: usb-storage: In hp8200e_transport() before usb_write_block(), cmnd = 0x1e. Feb 2 10:08:45 strider kernel: usb-storage: Transferred out 12 of 12 bytes Feb 2 10:08:45 strider kernel: usb-storage: In usbat_wait_not_busy(), waiting for 10 minutes. Feb 2 10:08:45 strider kernel: usb-storage: Waited not busy for 0 steps Feb 2 10:08:45 strider kernel: usb-storage: scsi cmd done, result=0x0 Feb 2 10:08:45 strider kernel: usb-storage: *** thread sleeping. Feb 2 10:08:45 strider kernel: usb-storage: queuecommand() called Feb 2 10:08:45 strider kernel: usb-storage: *** thread awakened. Feb 2 10:08:45 strider kernel: usb-storage: Command ALLOW_MEDIUM_REMOVAL (6 bytes) Feb 2 10:08:45 strider kernel: usb-storage: 1e 00 00 00 00 00 89 c3 00 00 00 00 Feb 2 10:08:45 strider kernel: usb-storage: Status = 50 Feb 2 10:08:45 strider kernel: usb-storage: Transferred out 14 of 14 bytes Feb 2 10:08:45 strider kernel: usb-storage: In usbat_wait_not_busy(), waiting for 0 minutes. Feb 2 10:08:45 strider kernel: usb-storage: Waited not busy for 0 steps Feb 2 10:08:45 strider kernel: usb-storage: In hp8200e_transport() before usb_write_block(), cmnd = 0x1e. Feb 2 10:08:45 strider kernel: usb-storage: Transferred out 12 of 12 bytes Feb 2 10:08:45 strider kernel: usb-storage: In usbat_wait_not_busy(), waiting for 10 minutes. Feb 2 10:08:45 strider kernel: usb-storage: Waited not busy for 0 steps Feb 2 10:08:45 strider kernel: usb-storage: scsi cmd done, result=0x0 Feb 2 10:08:45 strider kernel: usb-storage: *** thread sleeping. So the error arose during the second WRITE_10 after formatting completed. What should I try next? I'm still using the 2.4.17 patch that I downloaded on Dec 31. Could I expect any improvement if I change to the latest packet writing patch, or might the problem still be in the usb/storage layer? By the way, now that formatting is completed, will I need to do it again in future tests? Or will I be able to start with cdrwtool -u instead of -q ? 40 minutes is a long time to wait between tests... Drew -- PGP public key available at http://people.debian.org/~dparsons/drewskey.txt Fingerprint: A110 EAE1 D7D2 8076 5FE0 EC0A B6CE 7041 6412 4E4A
On Wed 16 Jan 2002 14:15, Drew Parsons wrote:
I'm trying to get packet writing working with a HP 8230e CDWriter, connecting via USB.
So do I, but I have the one that claims itself to be a 8290
Running cdrwtool to prepare the CD, I get:
=========================================================== #cdrwtool -d /dev/sr1 -t 4 -q using device /dev/sr1 setting speed to 4 cdrom: This disc doesn't have any tracks I recognize! 4085KB internal buffer setting write speed to 4x Settings for /dev/sr1: Fixed packets, size 32 Mode-2 disc
I'm going to do a quick setup of /dev/sr1. The disc is going to be blanked and formatted with one big track. All data on the device will be lost!! Press CTRL-C to cancel now.
Initiating quick disc blank Disc capacity is 275744 blocks (551488KB/538MB) Formatting track
Until here, we get the same (just not the internal buffer. Mine is 1312KB), but I got two additional lines: Writing UDF structures to disk -7200 (BRST)/120 and it hangs up. While you got stuck in the FORMAT_UNIT command, look at my log: Jan 24 17:42:21 mushroom kernel: usb-storage: *** thread awakened. Jan 24 17:42:21 mushroom kernel: usb-storage: Command MODE_SELECT_10 (10 bytes) Jan 24 17:42:21 mushroom kernel: usb-storage: 55 10 00 00 00 00 00 00 3c 00 00 00 Jan 24 17:42:21 mushroom kernel: usb-storage: Status = 50 Jan 24 17:42:21 mushroom kernel: usb-storage: Transferred out 38 of 38 bytes Jan 24 17:42:21 mushroom kernel: usb-storage: Transferred out 60 of 60 bytes Jan 24 17:42:21 mushroom kernel: usb-storage: Waited not busy for 0 steps Jan 24 17:42:21 mushroom kernel: usb-storage: Wrote 0000003C bytes Jan 24 17:42:21 mushroom kernel: usb-storage: scsi cmd done, result=0x0 Jan 24 17:42:21 mushroom kernel: usb-storage: *** thread sleeping. Jan 24 17:42:23 mushroom kernel: usb-storage: queuecommand() called Jan 24 17:42:23 mushroom kernel: usb-storage: *** thread awakened. Jan 24 17:42:23 mushroom kernel: usb-storage: Command BLANK (12 bytes) Jan 24 17:42:23 mushroom kernel: usb-storage: a1 01 00 00 00 00 00 00 00 00 00 00 Jan 24 17:42:23 mushroom kernel: usb-storage: Status = 50 Jan 24 17:42:23 mushroom kernel: usb-storage: Transferred out 14 of 14 bytes Jan 24 17:42:23 mushroom kernel: usb-storage: Waited not busy for 0 steps Jan 24 17:42:23 mushroom kernel: usb-storage: Transferred out 12 of 12 bytes Jan 24 17:43:56 mushroom kernel: usb-storage: Waited not busy for 1216 steps Jan 24 17:43:56 mushroom kernel: usb-storage: scsi cmd done, result=0x0 Jan 24 17:43:56 mushroom kernel: usb-storage: *** thread sleeping. Jan 24 17:43:56 mushroom kernel: usb-storage: queuecommand() called Jan 24 17:43:56 mushroom kernel: usb-storage: *** thread awakened. Jan 24 17:43:56 mushroom kernel: usb-storage: Command READ TRACK INFORMATION (10 bytes) Jan 24 17:43:56 mushroom kernel: usb-storage: 52 01 00 00 00 01 00 00 1c 00 00 00 Jan 24 17:43:56 mushroom kernel: usb-storage: Status = 50 Jan 24 17:43:56 mushroom kernel: usb-storage: Transferred out 14 of 14 bytes Jan 24 17:43:56 mushroom kernel: usb-storage: Waited not busy for 0 steps Jan 24 17:43:56 mushroom kernel: usb-storage: Transferred out 12 of 12 bytes Jan 24 17:43:56 mushroom kernel: usb-storage: Waited not busy for 1 steps Jan 24 17:43:56 mushroom kernel: usb-storage: Transferred in 28 of 28 bytes Jan 24 17:43:56 mushroom kernel: usb-storage: 00 1A 01 01 00 07 7F 01 00 00 00 00 00 00 00 00 Jan 24 17:43:56 mushroom kernel: usb-storage: 00 04 2D A0 00 00 00 20 00 04 2D A0 Jan 24 17:43:56 mushroom kernel: usb-storage: scsi cmd done, result=0x0 Jan 24 17:43:56 mushroom kernel: usb-storage: *** thread sleeping. Jan 24 17:43:56 mushroom kernel: usb-storage: queuecommand() called Jan 24 17:43:56 mushroom kernel: usb-storage: *** thread awakened. Jan 24 17:43:56 mushroom kernel: usb-storage: Command FORMAT_UNIT (6 bytes) Jan 24 17:43:56 mushroom kernel: usb-storage: 04 17 00 00 00 00 00 00 00 00 00 00 Jan 24 17:43:56 mushroom kernel: usb-storage: Status = 50 Jan 24 17:43:56 mushroom kernel: usb-storage: Transferred out 38 of 38 bytes Jan 24 17:43:56 mushroom kernel: usb-storage: Transferred out 16 of 16 bytes Jan 24 17:43:56 mushroom kernel: usb-storage: Waited not busy for 1 steps Jan 24 17:43:56 mushroom kernel: usb-storage: Wrote 0000004C bytes Jan 24 17:43:56 mushroom kernel: usb-storage: scsi cmd done, result=0x0 Jan 24 17:43:56 mushroom kernel: usb-storage: *** thread sleeping. Jan 24 17:43:56 mushroom kernel: usb-storage: queuecommand() called Jan 24 17:43:56 mushroom kernel: usb-storage: *** thread awakened. Jan 24 17:43:56 mushroom kernel: usb-storage: Command WRITE_10 (10 bytes) Jan 24 17:43:56 mushroom kernel: usb-storage: 2a 00 00 00 00 00 00 00 20 00 00 00 Jan 24 17:43:56 mushroom kernel: usb-storage: Status = 58 Jan 24 17:43:56 mushroom kernel: usb-storage: Transferred out 38 of 38 bytes Jan 24 17:43:56 mushroom kernel: usb-storage: Waited not busy for 0 steps Jan 24 17:43:56 mushroom kernel: usb-storage: Wrote 0001004C bytes Jan 24 17:43:56 mushroom kernel: usb-storage: scsi cmd done, result=0x0 Jan 24 17:43:56 mushroom kernel: usb-storage: *** thread sleeping. Jan 24 17:43:56 mushroom kernel: usb-storage: queuecommand() called Jan 24 17:43:56 mushroom kernel: usb-storage: *** thread awakened. Jan 24 17:43:56 mushroom kernel: usb-storage: Command WRITE_10 (10 bytes) Jan 24 17:43:56 mushroom kernel: usb-storage: 2a 00 00 00 01 00 00 00 20 00 00 00 Jan 24 17:43:56 mushroom kernel: usb-storage: Status = 58 Jan 24 17:43:56 mushroom kernel: usb-storage: Transferred out 38 of 38 bytes Jan 24 17:43:56 mushroom kernel: usb-storage: Waited not busy for 0 steps Jan 24 17:43:56 mushroom kernel: usb-storage: Wrote 0002004C bytes Jan 24 17:43:56 mushroom kernel: usb-storage: scsi cmd done, result=0x0 Jan 24 17:43:56 mushroom kernel: usb-storage: *** thread sleeping. Jan 24 17:43:56 mushroom kernel: usb-storage: queuecommand() called Jan 24 17:43:56 mushroom kernel: usb-storage: *** thread awakened. Jan 24 17:43:56 mushroom kernel: usb-storage: Command WRITE_10 (10 bytes) Jan 24 17:43:56 mushroom kernel: usb-storage: 2a 00 00 00 01 20 00 00 20 00 00 00 Jan 24 17:43:56 mushroom kernel: usb-storage: Status = 50 Jan 24 17:43:56 mushroom kernel: usb-storage: Transferred out 38 of 38 bytes Jan 24 17:44:01 mushroom kernel: usb-storage: command_abort() called Jan 24 17:44:01 mushroom kernel: usb-storage: CB_reset() called Jan 24 17:44:06 mushroom kernel: usb-storage: CB[I] soft reset failed -110 Jan 24 17:44:06 mushroom kernel: usb-storage: -- transport indicates transport failure Jan 24 17:44:06 mushroom kernel: usb-storage: scsi cmd done, result=0x70000 Jan 24 17:44:06 mushroom kernel: usb-storage: *** thread sleeping. This is very wierd, as it doesn't take 1 second to perform the FORMAT_UNIT command! Something wrong... Then, after the FORMAT_UNIT, it tries to write some data (the UDF structure, if i'm not wrong) to the CD and breaks up... Where can the problem be? -- Raphael Derosso Pereira - DephiNit *-=-*-=--=-*-=-*-=--=*=-* / dephinit@softhome.net / *-=-*-=--=-*-=-*-=--=*=-* -=*=--=*=--=*=--=*=--=*=--=*=--=*=- | Debian GNU/Linux Addicted User | | Use it, Abuse it. It's Free!!! | -=*=--=*=--=*=--=*=--=*=--=*=--=*=-
participants (4)
-
Ben Fennema -
Drew Parsons -
Ironhide -
Raphael Derosso Pereira - DephiNit