From owner-freebsd-bugs Sun Dec 13 22:32:34 1998 Return-Path: Received: (from majordom@localhost) by hub.freebsd.org (8.8.8/8.8.8) id WAA07508 for freebsd-bugs-outgoing; Sun, 13 Dec 1998 22:32:34 -0800 (PST) (envelope-from owner-freebsd-bugs@FreeBSD.ORG) Received: from mailb.telia.com (mailb.telia.com [194.22.194.6]) by hub.freebsd.org (8.8.8/8.8.8) with ESMTP id WAA07341 for ; Sun, 13 Dec 1998 22:31:59 -0800 (PST) (envelope-from listuser@netspace.net.au) Received: from d1o1.telia.com (root@d1o1.telia.com [195.67.240.241]) by mailb.telia.com (8.8.8/8.8.8) with ESMTP id HAA09249 for ; Mon, 14 Dec 1998 07:27:56 +0100 (CET) Received: from doorway.home.lan (t6o1p59.telia.com [195.67.241.119]) by d1o1.telia.com (8.8.8/8.8.5) with ESMTP id HAA19447 for ; Mon, 14 Dec 1998 07:27:52 +0100 (CET) Received: (from listuser@localhost) by doorway.home.lan (8.8.8/8.8.7) id GAA05863 for freebsd-bugs@FreeBSD.org; Mon, 14 Dec 1998 06:53:17 +0100 (CET) (envelope-from listuser) Date: Mon, 14 Dec 1998 06:53:17 +0100 (CET) From: List User Message-Id: <199812140553.GAA05863@doorway.home.lan> To: freebsd-bugs@FreeBSD.ORG Sender: owner-freebsd-bugs@FreeBSD.ORG Precedence: bulk X-Loop: FreeBSD.org Newsgroups: freebsd.bugs Path: root From: jtliu@phlebas.rockefeller.edu Subject: kern/9067: panic: vm_page_unhold: hold count < 0!!! when accessing CAM passthrough driver X-Send-Pr-Version: 3.2 Reply-To: jtliu@phlebas.rockefeller.edu Received: (from jtliu@localhost) by bulben.rockefeller.edu (8.8.8/8.8.5) id PAA08979; Sun, 13 Dec 1998 15:44:10 -0500 (EST) To: FreeBSD-gnats-submit Sender: owner-freebsd-bugs@FreeBSD.ORG Organization: Private News Host Message-ID: <199812132044.PAA08979@bulben.rockefeller.edu> X-Uidl: 185ab523f60cafe7d331fea67d33c458 X-Loop: FreeBSD.org Date: Sun, 13 Dec 1998 20:44:10 GMT >Number: 9067 >Category: kern >Synopsis: panic: vm_page_unhold: hold count < 0!!! when accessing CAM passthrough driver >Confidential: no >Severity: critical >Priority: high >Responsible: freebsd-bugs >State: open >Quarter: >Keywords: >Date-Required: >Class: sw-bug >Submitter-Id: current-users >Arrival-Date: Sun Dec 13 12:50:00 PST 1998 >Last-Modified: >Originator: James T. Liu >Organization: The Rockefeller University >Release: FreeBSD 3.0-RELEASE i386 >Environment: FreeBSD 3.0 running on a Pentium/100 with 32M memory and NCR 53c810 SCSI controller: speedy# dmesg Copyright (c) 1992-1998 FreeBSD Inc. Copyright (c) 1982, 1986, 1989, 1991, 1993 The Regents of the University of California. All rights reserved. FreeBSD 3.0-RELEASE #4: Fri Dec 11 19:45:00 EST 1998 jtliu@speedy:/usr/src/sys/compile/SPEEDY Timecounter "i8254" frequency 1193182 Hz cost 2759 ns Timecounter "TSC" frequency 99474243 Hz cost 225 ns CPU: Pentium/P54C (99.47-MHz 586-class CPU) Origin = "GenuineIntel" Id = 0x525 Stepping=5 Features=0x1bf real memory = 33554432 (32768K bytes) avail memory = 30408704 (29696K bytes) Probing for devices on PCI bus 0: chip0: rev 0x02 on pci0.0.0 chip1: rev 0x02 on pci0.7.0 ncr0: rev 0x02 int a irq 11 on pci0.10.0 vga0: rev 0x01 on pci0.11.0 ...cut... da0 at ncr0 bus 0 target 0 lun 0 da0: Fixed Direct Access SCSI2 device da0: 10.0MB/s transfers (10.0MHz, offset 8), Tagged Queueing Enabled da0: 1041MB (2131992 512 byte sectors: 255H 63S/T 132C) da1 at ncr0 bus 0 target 2 lun 0 da1: Fixed Direct Access SCSI2 device da1: 10.0MB/s transfers (10.0MHz, offset 8) da1: 1149MB (2354660 512 byte sectors: 255H 63S/T 146C) changing root device to da0s3a da2 at ncr0 bus 0 target 4 lun 0 da2: Fixed Direct Access SCSI2 device da2: 10.0MB/s transfers (10.0MHz, offset 8), Tagged Queueing Enabled da2: 2217MB (4541241 512 byte sectors: 255H 63S/T 282C) Start pid=2 Start pid=3 Start pid=4 cd1 at ncr0 bus 0 target 6 lun 0 cd1: Removable CD-ROM SCSI2 device cd1: 10.0MB/s transfers (10.0MHz, offset 8) cd1: cd present [307105 x 2048 byte records] cd0 at ncr0 bus 0 target 1 lun 0 cd0: Removable CD-ROM SCSI2 device cd0: 5.681MB/s transfers (5.681MHz, offset 8) cd0: Attempt to query device size failed: NOT READY, Medium not present speedy# camcontrol devlist at scbus0 target 0 lun 0 (pass0,da0) at scbus0 target 1 lun 0 (pass1,cd0) at scbus0 target 2 lun 0 (pass2,da1) at scbus0 target 4 lun 0 (pass3,da2) at scbus0 target 6 lun 0 (pass4,cd1) speedy# uname -a FreeBSD speedy 3.0-RELEASE FreeBSD 3.0-RELEASE #4: Fri Dec 11 19:45:00 EST 1998 jtliu@speedy:/usr/src/sys/compile/SPEEDY i386 In particular this kernel is configured with the options: options DIAGNOSTIC #for debugging panic options CAMDEBUG >Description: After upgrading to FreeBSD 3.0 (release), I also had to update some of the CDR related utilities for use with the new SCSI CAM system. In particular, I am using cdrecord 1.8a09 which includes a CAM aware cdda2wav. When running cdda2wav, I would get: Fatal trap 12: page fault while in kernel mode fault virtual address = 0xfff3 fault code = supervisor read, page not present instruction pointer = 0x8:0xf01ddb88 stack pointer = 0x10:0xf2ffecbc frame pointer = 0x10:0xf2ffecc4 code segment = base 0x0, limit 0xfffff, type 0x1b = DPL 0, pres 1, def32 1, gran 1 processor eflags = interrupt enabled, resume, IOPL = 0 current process = 883 (cdda2wav) interrupt mask = bio trap number = 12 panic: page fault after usually about 10-20 seconds of operation. After rebuilding the kernel with the DIAGNOSTIC option, I got a much more informative panic message which occurs right when cdda2wav starts ripping audio data: [speedy|61] /usr/libexec/aout/gdb -k kernel.2 vmcore.2 GDB is free software and you are welcome to distribute copies of it under certain conditions; type "show copying" to see the conditions. There is absolutely no warranty for GDB; type "show warranty" for details. GDB 4.16 (i386-unknown-freebsd), Copyright 1996 Free Software Foundation, Inc...(no debugging symbols found)... IdlePTD 2531328 initial pcb at 2445e0 panicstr: vm_page_unhold: hold count < 0!!! panic messages: --- panic: vm_page_unhold: hold count < 0!!! syncing disks... 23 23 11 done dumping to dev 70411, offset 132466 dump 32 31 30 29 28 27 26 25 24 23 22 21 20 19 18 17 16 15 14 13 12 11 10 9 8 7 6 5 4 3 2 1 --- #0 0xf01351eb in boot () (kgdb) where #0 0xf01351eb in boot () #1 0xf013550b in panic () #2 0xf01f7958 in vunmapbuf () #3 0xf0108641 in cam_periph_unmapmem () #4 0xf0115445 in passsendccb () #5 0xf011537a in passioctl () #6 0xf0163cf3 in spec_ioctl () #7 0xf016352d in spec_vnoperate () #8 0xf01d65d5 in ufs_vnoperatespec () #9 0xf015da5d in vn_ioctl () #10 0xf013e5d7 in ioctl () #11 0xf01f2b1f in syscall () #12 0xf01e88ac in Xint0x80_syscall () This certainly seems to be related to the cam passthrough device, as used by cdda2wav. Looking first at vunmapbuf(bp = 0xf1371a30) (/sys/i386/i386/vm_machdep.c), we find that the panic occurs with addr = 0xf2239000 and pa = 0. Clearly something is wrong with the latter. Looking at register struct buf *bp, we find: *bp = { b_hash = { le_next = 0x00000000, le_prev = 0x00000000 }, b_vnbufs = { le_next = 0x87654321, le_prev = 0x00000000 }, b_freelist = { tqe_next = 0x00000000, tqe_prev = 0x00000000 }, b_act = { tqe_next = 0x00000000, tqe_prev = 0x00000000 }, b_proc = 0x00000000, b_flags = 0x00140010 (B_READ|B_PHYS|B_BUSY), b_qindex/b_usecount = 0x00000000, b_error = 0x00000000, b_bufsize = 0x0001f950, b_bcount = 0x00000000, b_resid = 0x00000000, b_dev = 0x00000000, b_data = 0xf2219960, b_kvabase = 0xf2219000, b_kvasize = 0x00020000, b_lblkno = 0x00000000, b_blkno = 0x00000000, b_offset = 0x00000000 0x00000000, ... } In particular, note bp->b_bufsize = 0x0001f950 and bp->b_data = 0xf2219960 (which does not start on a page boundary). vunmapbuf() loops through all the pages without any difficulty until addr reaches 0xf2239000, and then the panic occurs. This seems to indicate that we are exceeding MAXPHYS since we actually started from the middle of a page (the data is being transfered to a non page aligned location). To complete the description, note that the system call originates from ReadCddaMMC12() (in scsi_cmds.c of cdda2wav) with a request to read 55 audio sectors of 2352 bytes (which is calculated to fall under MAXPHYS). This in turn ends up calling scsi_send() (in scsi-bsd.c) which calls cam_fill_csio() and cam_send_ccb(). This results in a CAMIOCOMMAND ioctl with a ccb function code of XPT_SCSI_IO. >How-To-Repeat: Install and run cdda2wav (with SCSI CAM transport) which is included as part of cdrecord-1.8a09.tar.gz (available at ftp://ftp.fokus.gmd.de/pub/unix/cdrecord/). >Fix: The ccb request size is checked in /sys/cam/cam_periph.c. Assuming the above description is correct, the following patch to cam_periph_mapmem() seems to fix the problem by accounting for any offset the buffer may have from a page boundary: diff -c ./cam_periph.c-3.0.0 ./cam_periph.c *** ./cam_periph.c-3.0.0 Thu Oct 15 13:46:18 1998 --- ./cam_periph.c Fri Dec 11 19:43:41 1998 *************** *** 486,500 **** switch(ccb->ccb_h.func_code) { case XPT_DEV_MATCH: ! if (ccb->cdm.pattern_buf_len > MAXPHYS) { printf("cam_periph_mapmem: attempt to map %u bytes, " "which is greater than MAXPHYS(%d)\n", ! ccb->cdm.pattern_buf_len, MAXPHYS); return(E2BIG); ! } else if (ccb->cdm.match_buf_len > MAXPHYS) { printf("cam_periph_mapmem: attempt to map %u bytes, " "which is greater than MAXPHYS(%d)\n", ! ccb->cdm.match_buf_len, MAXPHYS); return(E2BIG); } if (ccb->cdm.match_buf_len == 0) { --- 486,507 ---- switch(ccb->ccb_h.func_code) { case XPT_DEV_MATCH: ! if (ccb->cdm.pattern_buf_len + ! (((vm_offset_t)ccb->cdm.patterns)&PAGE_MASK) > MAXPHYS) { printf("cam_periph_mapmem: attempt to map %u bytes, " "which is greater than MAXPHYS(%d)\n", ! ccb->cdm.pattern_buf_len + ! (((vm_offset_t)ccb->cdm.patterns)&PAGE_MASK), ! MAXPHYS); return(E2BIG); ! } else if (ccb->cdm.match_buf_len + ! (((vm_offset_t)ccb->cdm.matches)&PAGE_MASK) ! > MAXPHYS) { printf("cam_periph_mapmem: attempt to map %u bytes, " "which is greater than MAXPHYS(%d)\n", ! ccb->cdm.match_buf_len + ! (((vm_offset_t)ccb->cdm.matches)&PAGE_MASK), ! MAXPHYS); return(E2BIG); } if (ccb->cdm.match_buf_len == 0) { *************** *** 518,527 **** } break; case XPT_SCSI_IO: ! if (ccb->csio.dxfer_len > MAXPHYS) { printf("cam_periph_mapmem: attempt to map %u bytes, " "which is greater than MAXPHYS(%d)\n", ! ccb->csio.dxfer_len, MAXPHYS); return(E2BIG); } --- 525,537 ---- } break; case XPT_SCSI_IO: ! if (ccb->csio.dxfer_len + ! (((vm_offset_t)ccb->csio.data_ptr)&PAGE_MASK) > MAXPHYS) { printf("cam_periph_mapmem: attempt to map %u bytes, " "which is greater than MAXPHYS(%d)\n", ! ccb->csio.dxfer_len + ! (((vm_offset_t)ccb->csio.data_ptr)&PAGE_MASK), ! MAXPHYS); return(E2BIG); } Note that this "fixes" the check for case XPT_DEV_MATCH as well, although I have no direct knowledge if there is any problem with that or not. In any case, after the addition of the above check, cdda2wav with default options no longer completes (but neither does it panic the kernel), as it now sees the E2BIG error: samplefile size will be 37189868 bytes. recording 210.82667 seconds stereo with 16 bits @ 4.41e+04 Hz ->'audio.wav'... ./cdda2wav: Undefined error: 0. WARNING: RR-scheduler not available, disabling. ./cdda2wav: Undefined error: 0. WARNING: RR-scheduler not available, disabling. ./cdda2wav: Argument list too long. Cannot send SCSI cmd via ioctl Request Sema 393216(1) failed: : Unknown error: 82 parent writer sem request failed, retry Request Sema 393216(1) failed: : Invalid argument However running cdda2wav with smaller buffers, e.g. cdda2wav -n 40 (specifying transfers of 40 sectors of 2352 bytes) works reliably. Here is a patch to cdrecord/scsi-bsd.c to properly account for MAXPHYS: diff -c scsi-bsd.c-orig scsi-bsd.c *** scsi-bsd.c-orig Mon Nov 2 16:22:24 1998 --- scsi-bsd.c Sun Dec 13 14:38:43 1998 *************** *** 575,581 **** long scsi_maxdma(scgp) SCSI *scgp; { ! return (MAXPHYS); } EXPORT void * --- 575,581 ---- long scsi_maxdma(scgp) SCSI *scgp; { ! return (MAXPHYS-PAGE_MASK); } EXPORT void * >Audit-Trail: >Unformatted: To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe freebsd-bugs" in the body of the message To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe freebsd-bugs" in the body of the message