April 2001 - Packet Writing - openSUSE Mailing Lists

0.0.2j/2.4.4 report
by Morten Bo Johansen 04 May '01

04 May '01

With ide-scsi I had the exact same problem as with 2.4.4pre6 and 0.0.2i as reported in <20010423224639.A593(a)olafrye.dyndns.org> , i.e. a complete lockup of my system so a hard reset was neccesary and alas I am still not able to make serial logging work so I cannot provide a bug report, sorry. I then tried to disable ide-scsi and this time at least the lockup is avoided but I get these errors instead: Formatting track Writing UDF structures to disc 7200 (CEST)/-120 hdd: irq timeout: status=0xd0 { Busy } hdd: Atapi reset complete wait_cmd: Input/output error Command failed: 2a 00 00 00 00 00 00 00 20 00 00 00 - sense 08.00.00 Error writing packet 0 (ffffffff) Regards, Morten -- "Life is all memory, except for the one present moment that goes by you so quick you hardly catch it going." (Tennessee Williams)

2 6

hang with 0.0.2j & 2.4.4 using cdrwtool
by rsmith＠xs4all.nl 02 May '01

02 May '01

After installing 2.4.4 with the 0.02j patch, I ran into the following difficulties: ---------------------- cdrwtool output ---------------------------------- slacker:/home/rsmith/tmp/src/udf-cvs/udf/tools# ./cdrwtool -d /dev/sr0 -q using device /dev/sr0 768KB internal buffer setting write speed to 12x Settings for /dev/sr0: Fixed packets, size 32 Mode-2 disc I'm going to do a quick setup of /dev/sr0. 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 275008 blocks (550016KB/537MB) Formatting track ---------------------- cdrwtool output ---------------------------------- There was one more line of output, something like: ---------------------- cdrwtool output ---------------------------------- 7200 (EST) ---------------------- cdrwtool output ---------------------------------- But it scrolled off the screen before I could write it down, and I can't remember the precise message. At this point a lot of error messages appeared in the log file: --------------------- /var/log/syslog ----------------------------------- Apr 29 13:22:59 slacker kernel: hdc: empty DMA table? Apr 29 13:23:04 slacker kernel: scsi : aborting command due to timeout : pid 0, scsi0, channel 0, id 1, lun 0 0x2a 00 00 00 00 00 00 00 20 00 Apr 29 13:23:09 slacker kernel: hdc: irq timeout: status=0xd0 { Busy } Apr 29 13:23:09 slacker kernel: hdc: DMA disabled Apr 29 13:23:09 slacker kernel: hdc: ATAPI reset complete Apr 29 13:23:09 slacker kernel: hdc: irq timeout: status=0xd0 { Busy } Apr 29 13:23:09 slacker kernel: scsi : aborting command due to timeout : pid 0, scsi0, channel 0, id 1, lun 0 0x2a 00 00 00 00 00 00 00 20 00 Apr 29 13:23:09 slacker kernel: SCSI host 0 abort (pid 0) timed out - resetting Apr 29 13:23:09 slacker kernel: SCSI bus is being reset for host 0 channel 0. Apr 29 13:23:10 slacker kernel: scsi : aborting command due to timeout : pid 0, scsi0, channel 0, id 1, lun 0 0x2a 00 00 00 00 00 00 00 20 00 Apr 29 13:23:10 slacker kernel: SCSI host 0 abort (pid 0) timed out - resetting Apr 29 13:23:10 slacker kernel: SCSI bus is being reset for host 0 channel 0. Apr 29 13:23:10 slacker kernel: scsi : aborting command due to timeout : pid 0, scsi0, channel 0, id 1, lun 0 0x2a 00 00 00 00 00 00 00 20 00 Apr 29 13:23:10 slacker kernel: SCSI host 0 abort (pid 0) timed out - resetting Apr 29 13:23:10 slacker kernel: SCSI bus is being reset for host 0 channel 0. Apr 29 13:23:12 slacker kernel: hdc: ATAPI reset complete Apr 29 13:23:12 slacker kernel: hdc: irq timeout: status=0xd0 { Busy } Apr 29 13:23:12 slacker kernel: hdc: status timeout: status=0xd0 { Busy } Apr 29 13:23:12 slacker kernel: hdc: drive not ready for command Apr 29 13:23:15 slacker kernel: hdc: ATAPI reset complete Apr 29 13:23:17 slacker kernel: scsi0 : channel 0 target 1 lun 0 request sense f ailed, performing reset. Apr 29 13:23:17 slacker kernel: SCSI bus is being reset for host 0 channel 0. Apr 29 13:23:18 slacker kernel: scsi0 : channel 0 target 1 lun 0 request sense f ailed, performing reset. Apr 29 13:23:18 slacker kernel: SCSI bus is being reset for host 0 channel 0. Apr 29 13:23:20 slacker kernel: scsi0 : channel 0 target 1 lun 0 request sense f ailed, performing reset. Apr 29 13:23:20 slacker kernel: SCSI bus is being reset for host 0 channel 0. Apr 29 13:23:22 slacker kernel: scsi0 : channel 0 target 1 lun 0 request sense f ailed, performing reset. Apr 29 13:23:22 slacker kernel: SCSI bus is being reset for host 0 channel 0. Apr 29 13:23:23 slacker kernel: scsi0 : channel 0 target 1 lun 0 request sense f ailed, performing reset. Apr 29 13:23:23 slacker kernel: SCSI bus is being reset for host 0 channel 0. Apr 29 13:23:24 slacker kernel: scsi0 : channel 0 target 1 lun 0 request sense f ailed, performing reset. Apr 29 13:23:24 slacker kernel: SCSI bus is being reset for host 0 channel 0. Apr 29 13:23:25 slacker kernel: scsi0 : channel 0 target 1 lun 0 request sense f ailed, performing reset. Apr 29 13:23:25 slacker kernel: SCSI bus is being reset for host 0 channel 0. Apr 29 13:23:26 slacker kernel: scsi0 : channel 0 target 1 lun 0 request sense f ailed, performing reset. Apr 29 13:23:26 slacker kernel: SCSI bus is being reset for host 0 channel 0. Apr 29 13:23:27 slacker kernel: scsi0 : channel 0 target 1 lun 0 request sense f ailed, performing reset. Apr 29 13:23:27 slacker kernel: SCSI bus is being reset for host 0 channel 0. --------------------- /var/log/syslog ----------------------------------- At this point, the box seemed to have hung completely; all disk activity ceased, it didn't respond to keyboard input anymore, and I did a hard reset. I've tried several times, but always with the same result. It always hangs at the end of the disk blanking c.q. beginning of the writing of the filesystem. My writer is a Philips CDD 3610, and I'm using scsi emulation. The CDRW disc I was using had been used before, but I used cdrecord to do a complete blank beforehand. I might add that pktsetup worked without errors, but mounting the disk failed of course, because it couldn't find a valid superblock. Some drive info: -------------------------- /proc data ------------------------------------ slacker:/home/rsmith# cat /proc/ide/hdc/model PHILIPS CDD3610 CD-R/RW slacker:/home/rsmith# cat /proc/ide/hdc/settings name value min max mode ---- ----- --- --- ---- bios_cyl 0 0 1023 rw bios_head 0 0 255 rw bios_sect 0 0 63 rw current_speed 33 0 69 rw ide_scsi 0 0 1 rw init_speed 33 0 69 rw io_32bit 0 0 3 rw keepsettings 0 0 1 rw log 0 0 1 rw nice1 1 0 1 rw number 2 0 3 rw pio_mode write-only 0 255 w slow 0 0 1 rw transform 1 0 3 rw unmaskirq 0 0 1 rw using_dma 1 0 1 rw slacker:/home/rsmith# cat /proc/ide/hdc/identify 8580 0000 0000 0000 0000 0000 0000 0000 0000 0000 3456 4f32 3239 3834 3831 3734 3332 3330 3032 3130 0000 1e78 0000 563a 3030 332e 3031 5048 494c 4950 5320 4344 4433 3631 3020 4344 2d52 2f52 5720 2020 2020 2020 2020 2020 2020 2020 2020 0000 0000 0b00 0000 0200 0200 0002 0000 0000 0000 0000 0000 0000 0000 0000 0007 0203 0001 007f 007f 00d0 007f 0000 0000 0000 <the rest of the data contained only 0s> slacker:/home/rsmith# cat /proc/ide/hdc/driver ide-scsi version 0.9 slacker:/home/rsmith# cat /proc/scsi/scsi Attached devices: Host: scsi0 Channel: 00 Id: 00 Lun: 00 Vendor: IOMEGA Model: ZIP 100 Rev: 23.D Type: Direct-Access ANSI SCSI revision: ffffffff Host: scsi0 Channel: 00 Id: 01 Lun: 00 Vendor: PHILIPS Model: CDD3610 CD-R/RW Rev: 3.01 Type: CD-ROM ANSI SCSI revision: 02 -------------------------- /proc data ------------------------------------ I hope this gives enough info. Roland -- Roland Smith "Traveler, there is no path. r s m i t h @ x s 4 a l l . n l You make the path as you walk." http://www.xs4all.nl/~rsmith/

4 4

lockups
by darrell pfeifer 30 Apr '01

30 Apr '01

Hello, I'm running the 2j release on 2.4.4 (release version), using an HP drive, ide-cd. FYI, I also get lockups. The mouse stops moving under X and I can't switch to another console. The good news is that waiting a bit will eventually unlock. The last lockup went for about 50 seconds, just before the data finished writing (don't know if that was a coincidence). I'll try the incremental patch I just saw come flying in. (By the way, the CD/Packet code is some of the nicest and best documented kernel code I've seen) darrell

2 1

cdrwtool fails again with 0.02j and kernel 2.4.4
by rsmith＠xs4all.nl 30 Apr '01

30 Apr '01

After the last failure with ide-scsi emulation enabled, I tried again with the ide-cd driver: ------------------------------ cdrwtool -------------------------------- slacker:/home/rsmith/tmp/src/udf-cvs/udf/tools# ./cdrwtool -d /dev/hdc -q using device /dev/hdc 768KB internal buffer setting write speed to 12x Settings for /dev/hdc: Fixed packets, size 32 Mode-2 disc I'm going to do a quick setup of /dev/hdc. The disc is going to be blanked and f ormatted 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 275008 blocks (550016KB/537MB) Formatting track Writing UDF structures to disc 7200 (CEST)/-120 wait_cmd: Input/output error Command failed: 2a 00 00 00 00 00 00 00 20 00 00 00 - sense 09.00.00 Error writing packet 0 (ffffffff) ------------------------------ cdrwtool -------------------------------- Nevertheless I inserted the pktcdvd module, and tried to mount the disk, just to see what happened. The accompanying errors from syslog are: --------------------------- /var/log/syslog ---------------------------- Apr 30 13:22:19 slacker kernel: hdc: irq timeout: status=0xd0 { Busy } Apr 30 13:22:19 slacker kernel: hdc: DMA disabled Apr 30 13:22:21 slacker kernel: hdc: ATAPI reset complete Apr 30 13:26:45 slacker kernel: hdc: irq timeout: status=0xd0 { Busy } Apr 30 13:26:47 slacker kernel: hdc: ATAPI reset complete Apr 30 13:29:58 slacker kernel: pktcdvd: inserted media is CD-RW Apr 30 13:29:58 slacker kernel: pktcdvd: Fixed packets, 32 blocks, Mode-2 disc Apr 30 13:29:58 slacker kernel: hdc: packet command error: status=0x51 { DriveRe ady SeekComplete Error } Apr 30 13:29:58 slacker kernel: hdc: packet command error: error=0x50 Apr 30 13:29:58 slacker kernel: ATAPI device hdc: Apr 30 13:29:58 slacker kernel: Error: Illegal request -- (Sense key=0x05) Apr 30 13:29:58 slacker kernel: Invalid field in command packet -- (asc=0x24, ascq=0x00) Apr 30 13:29:58 slacker kernel: The failed "Mode Sense 10" packet command was: Apr 30 13:29:58 slacker kernel: "5a 00 08 00 00 00 00 00 0c 00 00 00 " Apr 30 13:29:58 slacker kernel: pktcdvd: 550016kB available on disc Apr 30 13:30:07 slacker kernel: UDF-fs: No partition found (1) --------------------------- /var/log/syslog ---------------------------- Hope this helps. Roland -- Roland Smith "Traveler, there is no path. r s m i t h @ x s 4 a l l . n l You make the path as you walk." http://www.xs4all.nl/~rsmith/

1 0

packet-0.0.2j incremental fix
by Jens Axboe 30 Apr '01

30 Apr '01

Hi, There's a buffer count problem (reported by Stephen) in packet-0.0.2j, the attach patch should fix that. -- Jens Axboe

1 0

packet-0.0.2j
by Jens Axboe 30 Apr '01

30 Apr '01

Hi, Small stupid errors and a 2.4.4 kernel made me think that doing a completely fresh release was a good idea. Changes since packet-0.0.2i: - (0.0.2i-b) Fix compile error, pkt_put_buffer from pkt_end_io_read - Fix linking when ide-cd/sr modular and pktcdvd builtin - Remove SCSI_DEBUG_QUEUES, leave sanity segment check to final request state instead (makes more sense anyway now) - Add/correct config help entries - Merge 2.4.4 final - Remove throttling (see msg in packet-writing archive) - Remove request_cachep export again (used for throttling only) - Correctly kill request on I/O on media - Don't clear BH_Uptodate on failed buffer write (this is only valid for reads, see comment in source) Get it from *.kernel.org/pub/linux/kernel/people/axboe/packet or the sourceforge page. -- Jens Axboe

3 4

Best Sites #6A9B
by Martin Moere 29 Apr '01

29 Apr '01

***** This is an HTML Message ! *****

1 0

Device not ready errors
by Stephen Mollett 28 Apr '01

28 Apr '01

I am using 0.0.2i-pre3 with a Yamaha CRW4416S (SCSI3-MMC drive on an Adaptec AIC7880UW). When writing many files to a disc (eg. the kernel source), the driver seems to work OK to begin with: Detected scsi CD-ROM sr1 at scsi0, channel 0, id 2, lun 0 ... sr1: scsi3-mmc drive: 6x/6x writer cd/rw xa/form2 cdda tray ... pktcdvd: kernel thread pktcdvd0 started pktcdvd: writer sr1 sucessfully registered pktcdvd: speed (R/W) 3/2 pktcdvd: inserted media is CD-RW pktcdvd: Fixed packets, 32 blocks / packet, Mode-2 disc pktcdvd: enabled write caching on pktcdvd0 pktcdvd: speed (R/W) 3/2 pktcdvd: 540032kB available on disc [Lots of data written to disc, no errors in log] then suddenly floods the log with thousands of errors similar to: Device 0b:01 not ready: cmd=0, sector=95224, nr_sectors=8 or Device 0b:01 not ready: cmd=0, sector=628924, nr_sectors=68 Hope I've given sufficient information. Stephen Mollett

2 4

throttling and bad blocks
by Jens Axboe 28 Apr '01

28 Apr '01

Hi, I thought a bit more about the speed throttling I put in the latest release, and basically came to the conclusion that it shouldn't really be there. The low level drivers do their own retries of requests, and should do their own throttling too. Basically, when pktcdvd gets an I/O error from the lower layers the low level driver ought to have exhausted all possibilities wrt recovery. There's no point in doing retries etc at multiple levels, in fact it's pretty stupid. So I'm taking this code out again. But then, what should pktcdvd do on an I/O error? It should remap the packet location and resubmit the write. Ben, should we finally get this done? It's the last step in solid cd-rw writing, and absolutely critical if it's to be trusted. The problem with cd-rw is that UDF basically has to handle bad blocks and remapping. This is just one of the things that make it horrible to support, and why the format sucks. This sort of thing should be handled in hardware, like it is for any sane media. UDF will do its own read remapping for already remapped blocks I pressume (Ben?), if not pktcdvd can easily do it too (as long as I can get at the remap table). For writes, UDF needs to assign me a new start location for the packet. (UDF should to this too, but that would be much harder to support so I think for now we should let pktcvd do it). Comments? -- Jens Axboe

1 0

errors with 0.0.2i-b
by Graham Vincent 28 Apr '01

28 Apr '01

Hello. Here is the end of an attempt to build a new 2.4.3 kernel with the 0.0.2i-b packet writing patch applied. I updated the UDF version in the kernel to 0.9.3 before patching. Intel architecture. .... -o vmlinux drivers/block/block.o: In function `pkt_elevator_merge_req': drivers/block/block.o(.text+0x8a90): multiple definition of `pkt_elevator_merge_req' fs/fs.o(.text+0x2420): first defined here drivers/block/block.o: In function `pkt_elevator_cleanup': drivers/block/block.o(.text+0x8a94): multiple definition of `pkt_elevator_cleanup' fs/fs.o(.text+0x2424): first defined here fs/fs.o: In function `udf_set_blocksize': fs/fs.o(.text+0x587ec): undefined reference to `get_hardblocksize' make: *** [vmlinux] Error 1 .... Regards, Graham

2 1

packet-0.0.2i
by Jens Axboe 27 Apr '01

27 Apr '01

Hi, Woo, final 0.0.2i happened. Complete changelog, sort of: - Fix PKT_BUF_LIST error in fs/buffer.c - Fix pkt_find_dev in two spots, use q->queuedata in pkt_elevator_merge. - introduce pkt_make_request as READ remapper (and eventually add block remapper for WRITEs too). - Loose READ/WRITE checks in pkt_elevator_merge and pkt_request, they don't deal with anything but WRITEs after above change. - Fix pending request count in proc reading. - Fix increment usage bug for failed FMODE_WRITE opens. - Loose pd_lock/unlock, use io_request_lock for now. When block switches to per-queue lock, a search/replace operation will be sufficient. - Start to handle buffers non-uniform size buffers in a WRITE request. - Browse buffer cache hash table for possible bh victims - Fix blk_started_io to account buffers from buffer cache too - Do hole merging in regular elevator path - Fix bh_rq_in_between to look in the right direction - Remove sequencing from pkt_elevator - Use bh_cachep slab cache for private pool of buffer_heads - Remove old BH_Packet flag - Default udf to 2kB blocksize - Remove __getblk again - Remove rq->cmd checks in merge functions, only WRITEs now - Fix io_request_lock lockup when used with ATAPI (req->end_io) - Throttle down write when failed and retry, should write OPC entry when this happens - Use current time for b_flushtime in buffer.c for packet device, we don't want to postpone flushing a buffer if it causes read gathering - Remove all bh->b_private references, we could be stomping on other users (highmem, most notably). - Always use pkt_end_io_write as our bh->b_end_io callback - Added write caching config option (don't use yet) - Fixed missing brelse() for buffers stolen from buffer cache - Combine pkt_init_bh and pkt_recount_segments to only do one scan of request (pkt_init_rq) - Fix dupe buffer_head in pkt_hole_merge - Change buffer_head sequence check in ll_rw_blk, add to SCSI end_request handling - Missing MOD_DEC_USE_COUNT on failed bh list grow - Replace more pkt_find_dev with pkt_devs array lookup - Fix lockup on non-uptodate WRITE on ATAPI - Refile now cleaned dirty buffer when gotten from buffer cache - Add buffer/page cache hits statistics - Fix wait queue race due to unplug - Kill requests on buffer errors - Fixup sparc64 for new stats - Remove get_request_wait timeout, bug has been fixed - Cleanup rq clearing with pkt_end_request - Fix s/1/0 return from pkt_handle_queue on already busy - Cleanup pkt_request - Move default speed from 8 to 16 - Fix cleanup on error pkt_new_dev - Fixed nasty missing bh->b_reqnext list detachment in pkt_gather_data (solid hang, and possible corruption) - Only alloc PACKET_MAX_BUFFERS - 1 for freelist, save ~2kB mem - Remove pending bh count - Error compile on CONFIG_SCSI_DEBUG_QUEUES set, until fixed nicely - Fix pd locking, rely less on io_request_lock - Make sure only to try to throttle once per failed write - Remove kcdrwd startup/kill messages - Handle holes sanely, remove ll_rw_blk changes for that - Put pkt buffer on non-uptodate read *.kernel.org/pub/linux/kernel/people/axboe/packet/ or from the sourceforge page. -- Jens Axboe

1 1

Again "attempt to access beyond..."
by Ludovico Cavedon 26 Apr '01

26 Apr '01

I took a new cdrw, no damaged sectors, but the appmts to write beyond the devoce limit came back again. "df" reposrts size correctly, but log messages say "limit=2". Here is df output: -------------- Filesystem 1k-blocks Used Available Use% Mounted on /dev/hda4 6281212 3988236 2292976 64% / /dev/hda1 7746 7594 0 100% /boot /dev/hdc1 4210744 4086420 124324 98% /mirrors /dev/pktcdvd0 448320 34 448286 1% /cdrom ------------------ Here cdrwtool -i output: ------------------ 1148KB internal buffer setting write speed to 12x DISC INFO: erasable : Yes border = 3 Disc status = 2 number of first track = 1 number of sessions = 1 number of tracks = 1 status of last track = 1 uru = 0 did_v = 1 dbc_v = 0 disc type = 32 disc_id = 420582 OPC entries = 1 TRACK INFO: Track 1 track_number = 1 session_number = 1 damage = 0 copy = 0 track_mode = 7 Rt = 1 blank = 0 packet = 1 fp = 1 data_mode = 2 lra_v = 0 nwa_v = 1 track_start = 0 next_writable = 2560 last_recorded = 0 free_blocks = 0 packet_size = 32 track_size = 226912 (453824KB) ------------------------ My log attached. Bye, Ludovico Cavedon lumaca82(a)iniwind.it

2 1

Kernel panic with 0.0.2i-pre3
by Andreas Nowack 26 Apr '01

26 Apr '01

Hello, I tried 0.0.2i-pre3 and got a kernel panic (0.0.2i-pre1 worked fine). I tried to copy the kernel sources to a fresh CDRW. After a short while I got a kernel panic (syslog attached). After a reboot I had to write a new udf structure to the CDRW. "mkudf /dev/pktcdvd0" worked fine with 0.0.2i-pre3. I did a second attempt which also triggered a kernel panic (see second syslog). In the first case I found the message "kernel BUG at pktcdvd.c:1046!", while in the second case this message didn't appear. Best regards, Andreas

2 3

Re: [packet-writing] Results with 0.0.2i-pre2
by Ludovico Cavedon 25 Apr '01

25 Apr '01

On Wed, Apr 25, 2001 at 11:26:59AM +0200, Jens Axboe wrote: > On Tue, Apr 24 2001, Ludovico Cavedon wrote: > > lost+found is empty. Where are those 320Mb??? > > Good question :-). Did you get any UDF warnings in your logs? No, all was normal. But DirectCD sandisk reported damaged sectors... I'll try another cdrw. > > What sequence of commands of cdrwtool is equal to the "-q" option? > > Something like first a blank, then a format with fixed packet size set, > 32 block per packet, mode2 write mode. > > In commands, ala > > # cdrwtool -d /dev/sr0 -b > # cdrwtool -d /dev/sr0 -p -z 32 -s -m -u Thanx, bye, Ludovico Cavedon lumaca82(a)inwind.it

1 0

Results with 0.0.2i-pre2
by Ludovico Cavedon 25 Apr '01

25 Apr '01

Hi, I'm interested in packet writing and I've benn following thil ML for some weeks. Now I had time to try it on my computer. I followed the instructions. 1.Quick setup of a cd-rw 2.Mounted and unmounted it without writing (I hope the messages it wrote are only debug stuff, not errors...) 3. Mounted it again and copy 20 Mb in three files (sorry, my writer is only a 2x and i had not the time to thy the source kernel tree) 4. Unmounted The data is all readable, through windows too. But data is corruped: i use cmp to compare the files and they were different. I've attached the log. Bye, Ludovico Cavedon lumaca82(a)inwind.it

3 2

please test
by Jens Axboe 25 Apr '01

25 Apr '01

Hi folks, Could everybody with a cd-rw drive try the following program, and see if works (ie produces lba output) or if it complains about I/O error (and dumps a kernel message saying so, please send that too btw). axboe@burns:~/proggy $ sudo ./trigger_rahead /dev/hdc /dev/hdc: trigger LBA 1024, ra LBA 1050 Thanks -- Jens Axboe

10 16

packet-0.0.2i-pre3
by Jens Axboe 25 Apr '01

25 Apr '01

Hi, Next pre is up, changes since pre2: - Remove rq->cmd checks in merge functions, only WRITEs now - Fix io_request_lock lockup when used with ATAPI (req->end_io) - Throttle down write when failed and retry, should write OPC entry when this happens - Use current time for b_flushtime in buffer.c for packet device, we don't want to postpone flushing a buffer if it causes read gathering - Remove all bh->b_private references, we could be stomping on other users (highmem, most notably). - Always use pkt_end_io_write as our bh->b_end_io callback - Added write caching config option (don't use yet) - Added UDF empty block querying option - Fixed missing brelse() for buffers stolen from buffer cache - Combine pkt_init_bh and pkt_recount_segments to only do one scan of request (pkt_init_rq) - Fix dupe buffer_head in pkt_hole_merge - Change buffer_head sequence check in ll_rw_blk, add to SCSI end_request handling and it's been merged to 2.4.4-pre6. I'll hang on for final 0.0.2i until 2.4.4 is really released. *.kernel.org/pub/linux/kernel/people/axboe/packet/ As usual, there's a pre2 -> pre3 ugrade patch too. However, this one doesn't catch pre5 -> pre6, so I suggest getting 0.0.2i-pre3 from scratch. SCSI (Plextor 12/4/32) and ATAPI (Sony CRX100E) tested to the extent that large file copying was verified correct (100MB random data file), untarring 2.2.19 kernel source (and compiling it!), and various small files. No data loss of corruption detected, and it was all checked down to the very last byte. ATAPI used DMA mainly, PIO has also been tested good on this drive (just a large file copy, sanity verify). Note: although stuff like copying/untarring a kernel tree seems like fun, it isn't really a decent way to use packet writing. The pktcdvd module will do all it can to merge small writes together, but for decent performance one really should tar up small files before writing them to disc. For example, doing a make dep run on the 2.2.19 source ends up reading half the stuff from disc. Some writers are better at doing this quickly than others, the Sony beats the Plextor hands down in this sort of test (turning off laser, reading blocks, turn on and write). For the 100MB file copy, read gathering is almost exclusively due to getting the remaining parts of the packet that the UDF sparing table is written to. This is something we can't avoid (the WRITE), however I have plans for at least pinning the remaining blocks in memory. Right Ben? :-) Then arge file writes should go as fast as packet writing can go on your drive. Don't ask how long it takes to run make dep bzImage on a cd-rw stored kernel :-) (Un) fortunately I haven't had any failed writes on this particular disc just yet, so the write throttling path has not been exercised at all. It could be severly broken :-) Adam, I'll take a look at your scatter gather segment miscount next. I suspect this happens because of a requeue of the request. -- Jens Axboe

3 12

better performance
by Jens Axboe 24 Apr '01

24 Apr '01

Hi, For better performance when doing stuff like untars or kernel tree copies, run something like $ while true; do sync; done in a 2nd term. The reason for the boost is simple -- we want to keep our request queue full at all times, to allow the best merging possible. This usually happens (the request free batching helps a lot), but not always because bdflush doesn't push enough buffers out at once at seemingly random intervals. I've thought about doing pull-flushing before (rather than push flushing as it happens now) for other reasons in fact, however that would solve this issue completely too. More on this soon :-) -- Jens Axboe

1 0

attempt to access beyond end of device
by Jens Axboe 24 Apr '01

24 Apr '01

Hi, Could the folks seeing this error please do: # cdrwtool -d /dev/my_cd_device -i with the disc used inserted, and send me the output? Thanks. -- Jens Axboe

1 0

Results with 0.0.2i-pre3
by Adam Huffman 24 Apr '01

24 Apr '01

Hmm, this time I get the return of some errors I used to get with a much earlier version of the patch. Instead of copying a kernel tree, I tried a 33Mb RPM on a SCSI Zip disk. It did copy, eventually, after the torrent of messages, but it cannot be queried or verified. Here's a sample of the messages: pktcdvd: kernel thread pktcdvd0 started pktcdvd: writer sr0 sucessfully registered pktcdvd: inserted media is CD-RW pktcdvd: Fixed packets, 32 blocks / packet, Mode-2 disc pktcdvd: enabled write caching on pktcdvd0 pktcdvd: speed (R/W) 6/4 pktcdvd: 452288kB available on disc UDF-fs INFO UDF 0.9.3-rw (2000/12/25) Mounting volume '', timestamp 2001/04/24 00:46 (103c) attempt to access beyond end of device 0b:00: rw=0, want=710, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=712, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=714, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=716, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=718, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=720, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=722, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=724, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=726, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=728, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=730, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=732, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=734, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=736, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=738, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=740, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=742, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=744, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=746, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=748, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=750, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=752, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=754, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=756, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=758, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=760, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=762, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=764, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=766, limit=2 attempt to access beyond end of device 0b:00: rw=0, want=768, limit=2 huh, 1416 not uptodate huh, 1420 not uptodate huh, 1424 not uptodate huh, 1428 not uptodate huh, 1432 not uptodate huh, 1436 not uptodate huh, 1440 not uptodate huh, 1444 not uptodate huh, 1448 not uptodate huh, 1452 not uptodate huh, 1456 not uptodate huh, 1460 not uptodate huh, 1464 not uptodate huh, 1468 not uptodate huh, 1472 not uptodate huh, 1476 not uptodate huh, 1480 not uptodate huh, 1484 not uptodate huh, 1488 not uptodate huh, 1492 not uptodate huh, 1496 not uptodate huh, 1500 not uptodate huh, 1504 not uptodate huh, 1508 not uptodate huh, 1512 not uptodate huh, 1516 not uptodate huh, 1520 not uptodate huh, 1524 not uptodate huh, 1528 not uptodate huh, 1532 not uptodate 1416 not uptodate 1420 not uptodate 1424 not uptodate 1428 not uptodate 1432 not uptodate 1436 not uptodate 1440 not uptodate 1444 not uptodate 1448 not uptodate 1452 not uptodate 1456 not uptodate 1460 not uptodate 1464 not uptodate 1468 not uptodate 1472 not uptodate 1476 not uptodate 1480 not uptodate 1484 not uptodate 1488 not uptodate 1492 not uptodate 1496 not uptodate 1500 not uptodate 1504 not uptodate 1508 not uptodate 1512 not uptodate 1516 not uptodate 1520 not uptodate 1524 not uptodate 1528 not uptodate 1532 not uptodate Sorry for sending bad news twice in one evening... Adam

2 1

debugging hard lockups
by Jens Axboe 23 Apr '01

23 Apr '01

Hi, I think most of the hard hangs people are seeing are actually induced on purpose. The BUG() will hard hang a machine at times, usually because interrupts are disabled or just because we are holding a spin lock. Because of that, to debug a hard hang without a serial console you can do something like... : #undef BUG #define BUG() do { \ printk("kernel BUG at %s:%d!\n", __FILE__, __LINE__); \ } while (0); right before the SCSI_IOCTL_SEND_COMMAND define in drivers/block/pktcdvd.c and recompile the kernel/module. _If_ you choose to do so, look for these messages in your logs repeatedly -- I definitely don't want to miss one of them, that's why they are BUG's now. -- Jens Axboe

1 0

packet-0.0.2i-pre2
by Jens Axboe 23 Apr '01

23 Apr '01

Hi, I put up a 0.0.2i-pre2 patch, which is basically what will be the final version. It has all the fixes and changes that I want in the final, but I figured I'd let it spin for a day before releasing final 0.0.2i. List of changes from 0.0.2h so far: - Fix PKT_BUF_LIST error in fs/buffer.c - Fix pkt_find_dev in two spots, use q->queuedata in pkt_elevator_merge. - introduce pkt_make_request as READ remapper (and eventually add block remapper for WRITEs too). - Loose READ/WRITE checks in pkt_elevator_merge and pkt_request, they don't deal with anything but WRITEs after above change. - Fix pending request count in proc reading. - Fix increment usage bug for failed FMODE_WRITE opens. - Loose pd_lock/unlock, use io_request_lock for now. When block switches to per-queue lock, a search/replace operation will be sufficient. - Start to handle buffers non-uniform size buffers in a WRITE request. - Browse buffer cache hash table for possible bh victims - Fix blk_started_io to account buffers from buffer cache too - Do hole merging in regular elevator path - Fix bh_rq_in_between to look in the right direction - Remove sequencing from pkt_elevator - Use bh_cachep slab cache for private pool of buffer_heads - Remove old BH_Packet flag - Default udf to 2kB blocksize - Remove __getblk again Get it here: *.kernel.org/pub/linux/kernel/people/axboe/packet/ while it's hot. 0.0.2i-pre1 -> 0.0.2i-pre2 patch attached. -- Jens Axboe

4 11

Oops with latest patch
by Adam Huffman 23 Apr '01

23 Apr '01

Had multiple Oopsen when copying to a newly-formatted and mounted disc. Here is the first one: pktcdvd: inserted media is CD-RW pktcdvd: Fixed packets, 32 blocks / packet, Mode-2 disc pktcdvd: enabled write caching on pktcdvd0 pktcdvd: speed (R/W) 6/4 pktcdvd: 452288kB available on disc Incorrect segment count at 0xc01c2af7nr_segments is 4 counted segments is 6 Flags 1 0 Segment 0xc3049f80, blocks 4, addr 0x2ec17ff Segment 0xc3049f20, blocks 4, addr 0x2ee5fff Segment 0xc3049ec0, blocks 4, addr 0x2ee67ff Segment 0xc3049da0, blocks 4, addr 0x1675fff Segment 0xc3049d40, blocks 4, addr 0x16767ff Segment 0xc3049b00, blocks 4, addr 0x2c71fff Segment 0xc3049c80, blocks 4, addr 0x2c727ff Segment 0xc3049a40, blocks 4, addr 0x2cc2fff Kernel panic: Ththththaats all folks. Too dangerous to continue. ksymoops -m /boot/System.map-2.4.4-pre5 < udf-oops-24-04-2001 ksymoops 2.3.5 on i586 2.4.4-pre5. Options used -V (default) -k /proc/ksyms (default) -l /proc/modules (default) -o /lib/modules/2.4.4-pre5/ (default) -m /boot/System.map-2.4.4-pre5 (specified) Warning (compare_maps): ksyms_base symbol __VERSIONED_SYMBOL(shmem_file_setup) not found in System.map. Ignoring ksyms_base entry invalid operand: 0000 CPU: 0 EIP: 0010:[<c11e4336>] Using defaults from ksymoops -t elf32-i386 -a i386 EFLAGS: 00010002 eax: c2f1f074 ebx: 00000001 ecx: c2f1f000 edx: 00000001 esi: c1155860 edi: c30497a0 ebp: c2f1f074 esp: c115fd50 ds: 0018 es: 0018 ss: 0018 Process bdflush (pid: 6, stackpage=c115f000) Stack: c4833f4a c2f1f074 00000001 c30497a0 c30497a0 00000004 00000184 00006100 c017e9ea c2f1f074 00000001 c30497a0 00000000 c0192d99 00000001 c30497a0 c30497a0 00000004 00000001 00000001 c017ea5d 00000001 c30497a0 c30497a0 Call Trace: [<c4833f4a>] [<c017e9ea>] [<c0192d99>] [<c017ea5d>] [<c017ece7>] [<c019d09b>] [<c019d0bd>] [<c012f784>] [<c0112316>] [<c012f8a3>] [<c012f8c7>] [<c0111de5>] [<c01c2b46>] [<c01c2af7>] [<c4832267>] [<c01c2ab0>] [<c017e333>] [<c01afe80>] [<c01b6e40>] [<c0107fca>] [<c4833f4a>] [<c017e9ea>] [<c017ea5d>] [<c017ece7>] [<c0132508>] [<c013272c>] [<c0105000>] [<c0105000>] [<c0105496>] [<c01326b0>] Code: ff ff 00 08 00 00 00 00 00 00 00 00 00 00 00 00 00 00 02 00 P; c11e4336 <_end+eae51e/44e1248> <===== Trace; c4833f4a <[pktcdvd]pkt_make_request+5a/70> Trace; c017e9ea <generic_make_request+14a/160> Trace; c0192d99 <scrup+69/110> Trace; c017ea5d <submit_bh+5d/90> Trace; c017ece7 <ll_rw_block+207/250> Trace; c019d09b <serial_console_write+11b/1b0> Trace; c019d0bd <serial_console_write+13d/1b0> Trace; c012f784 <sync_buffers+c4/1a0> Trace; c0112316 <printk+156/170> Trace; c012f8a3 <fsync_dev+13/30> Trace; c012f8c7 <sys_sync+7/10> Trace; c0111de5 <panic+65/e0> Trace; c01c2b46 <scsi_back_merge_fn_c+96/f0> Trace; c01c2af7 <scsi_back_merge_fn_c+47/f0> Trace; c4832267 <[pktcdvd]pkt_back_merge_fn+97/b0> Trace; c01c2ab0 <scsi_back_merge_fn_c+0/f0> Trace; c017e333 <__make_request+183/6f0> Trace; c01afe80 <ide_intr+f0/150> Trace; c01b6e40 <read_intr+0/160> Trace; c0107fca <handle_IRQ_event+3a/70> Trace; c4833f4a <[pktcdvd]pkt_make_request+5a/70> Trace; c017e9ea <generic_make_request+14a/160> Trace; c017ea5d <submit_bh+5d/90> Trace; c017ece7 <ll_rw_block+207/250> Trace; c0132508 <flush_dirty_buffers+78/c0> Trace; c013272c <bdflush+7c/e0> Trace; c0105000 <init+0/130> Trace; c0105000 <init+0/130> Trace; c0105496 <kernel_thread+26/30> Trace; c01326b0 <bdflush+0/e0> Code; c11e4336 <_end+eae51e/44e1248> 00000000 <_EIP>: Code; c11e4336 <_end+eae51e/44e1248> <===== 0: ff (bad) <===== Code; c11e4337 <_end+eae51f/44e1248> 1: ff 00 incl (%eax) Code; c11e4339 <_end+eae521/44e1248> 3: 08 00 or %al,(%eax) Code; c11e4347 <_end+eae52f/44e1248> 11: 00 02 add %al,(%edx) 1 warning issued. Results may not be reliable. then a kernel message: rq->cmd=1, rq->sector=10768, rq->nr_sectors=112 kernel BUG at pktcdvd.c:995! then another Oops: Warning (compare_maps): ksyms_base symbol __VERSIONED_SYMBOL(shmem_file_setup) not found in System.map. Ignoring ksyms_base entry invalid operand: 0000 CPU: 0 EIP: 0010:[<c483312a>] Using defaults from ksymoops -t elf32-i386 -a i386 EFLAGS: 00010086 eax: 0000001d ebx: c3b5ff60 ecx: c2556000 edx: c02b1624 esi: 00002a10 edi: c1155860 ebp: c2f1f074 esp: c2d9bf88 ds: 0018 es: 0018 ss: 0018 Process pktcdvd0 (pid: 926, stackpage=c2d9b000) Stack: c4834d34 c4834e69 000003e3 c2d9a000 00000000 c115e000 c0305540 c2d9a000 c2f1f074 c2f1f000 c1155878 c4832ff4 c2f1f074 c2f1f09c 00000000 c2d9a000 00000000 00000000 00000000 c2d9a000 c2f1f110 c2f1f110 00000f00 c13f1f1c Call Trace: [<c4834d34>] [<c4834e69>] [<c4832ff4>] [<c0105496>] [<c4832f00>] Code: 0f 0b 83 c4 0c b8 06 00 00 00 0f ab 47 48 19 c0 85 c0 75 1e >>EIP; c483312a <[pktcdvd]pkt_request+ca/120> <===== Trace; c4834d34 <[pktcdvd].rodata.start+34/eff> Trace; c4834e69 <[pktcdvd].rodata.start+169/eff> Trace; c4832ff4 <[pktcdvd]kcdrwd+f4/160> Trace; c0105496 <kernel_thread+26/30> Trace; c4832f00 <[pktcdvd]kcdrwd+0/160> Code; c483312a <[pktcdvd]pkt_request+ca/120> 00000000 <_EIP>: Code; c483312a <[pktcdvd]pkt_request+ca/120> <===== 0: 0f 0b ud2a <===== Code; c483312c <[pktcdvd]pkt_request+cc/120> 2: 83 c4 0c add $0xc,%esp Code; c483312f <[pktcdvd]pkt_request+cf/120> 5: b8 06 00 00 00 mov $0x6,%eax Code; c4833134 <[pktcdvd]pkt_request+d4/120> a: 0f ab 47 48 bts %eax,0x48(%edi) Code; c4833138 <[pktcdvd]pkt_request+d8/120> e: 19 c0 sbb %eax,%eax Code; c483313a <[pktcdvd]pkt_request+da/120> 10: 85 c0 test %eax,%eax Code; c483313c <[pktcdvd]pkt_request+dc/120> 12: 75 1e jne 32 <_EIP+0x32> c483315c <[pktcdvd]pkt_request+fc/120> 1 warning issued. Results may not be reliable. and another one: Warning (compare_maps): ksyms_base symbol __VERSIONED_SYMBOL(shmem_file_setup) not found in System.map. Ignoring ksyms_base entry Unable to handle kernel NULL pointer dereference at virtual address 00000000 00000000 *pde = 00000000 Oops: 0000 CPU: 0 EIP: 0010:[<00000000>] Using defaults from ksymoops -t elf32-i386 -a i386 EFLAGS: 00010282 eax: c03224e0 ebx: c2c59e40 ecx: 00000000 edx: 00000000 esi: 00000004 edi: 00000184 ebp: 00000000 esp: c13f1bb4 ds: 0018 es: 0018 ss: 0018 Process cp (pid: 930, stackpage=c13f1000) Stack: c017e9ea c03224e0 00000000 c2c59e40 00000006 00000003 00000006 c2c59e40 c2c59e40 00000004 00000000 00000000 c017ea5d 00000000 c2c59e40 c2c59e40 00000000 c2c59e40 c017ece7 00000000 c2c59e40 c13f0000 c2c59e40 c2c59e40 Call Trace: [<c017e9ea>] [<c017ea5d>] [<c017ece7>] [<c01307f5>] [<c48445d9>] [<c48445eb>] [<c0198fe6>] [<c019924e>] [<c0107fca>] [<c010814d>] [<c010816c>] [<c0106ce0>] [<c4841bf0>] [<c01ae698>] [<c01b6f81>] [<c01b6e40>] [<c01ae698>] [<c01b6f81>] [<c01b6e40>] [<c0107fca>] [<c48418ac>] [<c0130f57>] [<c0121120>] [<c01316b1>] [<c4841800>] [<c0123cd0>] [<c4841800>] [<c0139a53>] [<cd000000>] [<c484087c>] [<c012e9a6>] [<c0106c23>] Code: Bad EIP value. >>EIP; 00000000 Before first symbol Trace; c017e9ea <generic_make_request+14a/160> Trace; c017ea5d <submit_bh+5d/90> Trace; c017ece7 <ll_rw_block+207/250> Trace; c01307f5 <bread+35/70> Trace; c48445d9 <[udf]udf_next_aext+3d/418> Trace; c48445eb <[udf]udf_next_aext+4f/418> Trace; c0198fe6 <transmit_chars+d6/e0> Trace; c019924e <rs_interrupt_single+6e/90> Trace; c0107fca <handle_IRQ_event+3a/70> Trace; c010814d <do_IRQ+6d/b0> Trace; c010816c <do_IRQ+8c/b0> Trace; c0106ce0 <ret_from_intr+0/20> Trace; c4841bf0 <[udf]inode_getblk+204/77c> Trace; c01ae698 <ide_set_handler+58/60> Trace; c01b6f81 <read_intr+141/160> Trace; c01b6e40 <read_intr+0/160> Trace; c01ae698 <ide_set_handler+58/60> Trace; c01b6f81 <read_intr+141/160> Trace; c01b6e40 <read_intr+0/160> Trace; c0107fca <handle_IRQ_event+3a/70> Trace; c48418ac <[udf]udf_get_block+ac/12c> Trace; c0130f57 <__block_prepare_write+e7/260> Trace; c0121120 <add_to_page_cache_unique+d0/e0> Trace; c01316b1 <block_prepare_write+21/40> Trace; c4841800 <[udf]udf_get_block+0/12c> Trace; c0123cd0 <generic_file_write+3d0/560> Trace; c4841800 <[udf]udf_get_block+0/12c> Trace; c0139a53 <open_namei+353/5d0> Trace; cd000000 <END_OF_CODE+87aec61/??? Trace; c484087c <[udf]udf_file_write+f8/12c> Trace; c012e9a6 <sys_write+96/d0> Trace; c0106c23 <system_call+33/40> 1 warning issued. Results may not be reliable. Most of the rest of them are kernel BUG at exit.c:458! Hardware is a Yamaha 8424 internal SCSI on an Adaptec 2904. Adam

2 3

Latest patch
by Adam Huffman 21 Apr '01

21 Apr '01

Compiled and installed the latest patch now, made a new UDF disc and tried to mount it, but each time I get the following error: UDF-fs: No partition found (1) The same disc can be mounted (read-only) on another box, using the normal kernel udf support. Adam

2 5

packet-0.0.2i-pre1
by Jens Axboe 21 Apr '01

21 Apr '01

Hi, Due to the stupid error in 0.0.2h, I put up a 0.0.2i-pre1. There's also a 2h -> 2i-pre1 patch since it's so small, attached here as well. The pre versions will only be put on kernel.org, brw. -- Jens Axboe

1 0