From owner-freebsd-bugs@FreeBSD.ORG Sun Oct 16 20:40:19 2005 Return-Path: X-Original-To: freebsd-bugs@hub.freebsd.org Delivered-To: freebsd-bugs@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id AA0C916A420 for ; Sun, 16 Oct 2005 20:40:19 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id 9EBEA43D48 for ; Sun, 16 Oct 2005 20:40:17 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j9GKeHeh000539 for ; Sun, 16 Oct 2005 20:40:17 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j9GKeHu0000533; Sun, 16 Oct 2005 20:40:17 GMT (envelope-from gnats) Resent-Date: Sun, 16 Oct 2005 20:40:17 GMT Resent-Message-Id: <200510162040.j9GKeHu0000533@freefall.freebsd.org> Resent-From: FreeBSD-gnats-submit@FreeBSD.org (GNATS Filer) Resent-To: freebsd-bugs@FreeBSD.org Resent-Reply-To: FreeBSD-gnats-submit@FreeBSD.org, M Joonas Pihlaja Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 5676616A41F for ; Sun, 16 Oct 2005 20:39:56 +0000 (GMT) (envelope-from joonas@3jane.math.ualberta.ca) Received: from 3jane.math.ualberta.ca (3jane.math.ualberta.ca [129.128.206.44]) by mx1.FreeBSD.org (Postfix) with ESMTP id D31B743D46 for ; Sun, 16 Oct 2005 20:39:55 +0000 (GMT) (envelope-from joonas@3jane.math.ualberta.ca) Received: from 3jane.math.ualberta.ca (localhost.math.ualberta.ca [127.0.0.1]) by 3jane.math.ualberta.ca (8.13.3/8.13.1) with ESMTP id j9GKdt3j001310; Sun, 16 Oct 2005 14:39:55 -0600 (MDT) (envelope-from joonas@3jane.math.ualberta.ca) Received: (from joonas@localhost) by 3jane.math.ualberta.ca (8.13.3/8.13.1/Submit) id j9GKdtEB001309; Sun, 16 Oct 2005 14:39:55 -0600 (MDT) (envelope-from joonas) Message-Id: <200510162039.j9GKdtEB001309@3jane.math.ualberta.ca> Date: Sun, 16 Oct 2005 14:39:55 -0600 (MDT) From: joonas To: FreeBSD-gnats-submit@FreeBSD.org X-Send-Pr-Version: 3.113 Cc: Machine Owner Subject: misc/87544: mmaping large files on a gbde filesystem deadlocks the system X-BeenThere: freebsd-bugs@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: M Joonas Pihlaja List-Id: Bug reports List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 16 Oct 2005 20:40:19 -0000 >Number: 87544 >Category: misc >Synopsis: mmaping large files on a gbde filesystem deadlocks the system >Confidential: no >Severity: serious >Priority: medium >Responsible: freebsd-bugs >State: open >Quarter: >Keywords: >Date-Required: >Class: sw-bug >Submitter-Id: current-users >Arrival-Date: Sun Oct 16 20:40:16 GMT 2005 >Closed-Date: >Last-Modified: >Originator: joonas >Release: FreeBSD 5.4-RC3 amd64 >Organization: Helsinki University >Environment: System: FreeBSD 3jane.math.ualberta.ca 5.4-RC3 FreeBSD 5.4-RC3 #1: Wed Sep 14 13:20:57 MDT 2005 bvowk@3jane.math.ualberta.ca:/usr/obj/usr/src/sys/SMP amd64 Hi, It appears that large file i/o using mmap on files residing in an encrypted filesystem may deadlock the kernel. The problem is repeatable using the python program below, a test of a large 2D byte array class using mmap backed files. Machine details: 3jane: ~ $ uname -a FreeBSD 3jane.math.ualberta.ca 5.4-RC3 FreeBSD 5.4-RC3 #1: Wed Sep 14 13:20:57 MDT 2005 bvowk@3jane.math.ualberta.ca:/usr/obj/usr/src/sys/SMP amd64 3jane: ~ $ python Python 2.4 (#2, Feb 9 2005, 09:38:26) [GCC 3.4.2 [FreeBSD] 20040728] on freebsd5 Type "help", "copyright", "credits" or "license" for more information. >Description: The python program does this: write an ~1GB file, mmap it into memory using MAP_SHARED and PROT_READ|PROT_WRITE, write a byte to every 80000'th byte in the file, unmap file; rinse & repeat five more times. Sometime after writing out the first file it seems like the system deadlocks. Namely, system cpu usage is up at 75%, 25% idle, with no i/o happening at all. The system won't come out of deadlock, won't respond to ssh, but must be manually rebooted. My sysadmin said he could type on the console, but the system didn't respond. >How-To-Repeat: Cut & paste the following program into tmp.py and run "python tmp.py" in a directory on an encrypted filesystem. Open another window, go to the directory, and repeatedly do ls -lrt. At some point the system will hang. On a gbde file system io stops completely. When run on a non-gbde file system the the disks churn like mad, and even though repeated ls -lrt hang also then, it also unhangs after a while and the program completes successfully. ---START--- import sys import mmap import os # python is choking at mmap indices ~ 220M. MAXCHUNKSIZE = 1024*1024*1024L WANTCHUNKSIZE = MAXCHUNKSIZE class charary: def __init__(self, basename, width, height, initval='\000'): self.width = width self.height = height self.basename = basename self.initval = initval totbytes = int(width)*1L*int(height) maxchunksize = WANTCHUNKSIZE self.rows_per_chunk = (maxchunksize + width - 1) / width while self.rows_per_chunk*width > MAXCHUNKSIZE: self.rows_per_chunk += -1 self.chunksize = self.rows_per_chunk * width self.nchunks = (totbytes + self.chunksize-1) / self.chunksize assert self.rows_per_chunk > 0 self.curchix = None; self.curmap = None def initfile(self, fd, size): i=0 len = 16384 block = self.initval * len os.lseek(fd, 0, 0) while i + len < size: os.write(fd, block) i += len while i < size: os.write(fd, self.initval) i += 1 os.lseek(fd, 0, 0) def mapchunk(self, chix): if chix <> self.curchix: if self.curmap <> None: self.curmap.close() self.curmap = None filename = "%s%03d" % (self.basename, chix) filesize = self.chunksize if chix == self.nchunks - 1: filesize = (self.height % self.rows_per_chunk)*self.width fd = os.open(filename, os.O_RDWR | os.O_CREAT) sbuf = os.fstat(fd) if sbuf.st_size < filesize: self.initfile(fd, filesize) self.curchix = chix self.curmap = mmap.mmap(fd, filesize, mmap.MAP_SHARED) return self.curmap def get(self,x,y): chix = y / self.rows_per_chunk c = self.mapchunk(chix) y = y % self.rows_per_chunk return c[x + self.width*y] def set(self,x,y,val): chix = y / self.rows_per_chunk c = self.mapchunk(chix) y = y % self.rows_per_chunk c[x + self.width*y] = val def close(self): if self.curchix <> None: self.curmap.close() self.curchix = None self.curmap = None n=80000 a = charary("./ary", n, n) for i in xrange(n): a.get(10, i) a.set(10,i,'A') ---END--- Best Regards, Joonas >Fix: >Release-Note: >Audit-Trail: >Unformatted: >>> 3jane: ~ $ dmesg Copyright (c) 1992-2005 The FreeBSD Project. Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994 The Regents of the University of California. All rights reserved. FreeBSD 5.4-RC3 #1: Wed Sep 14 13:20:57 MDT 2005 bvowk@3jane.math.ualberta.ca:/usr/obj/usr/src/sys/SMP Timecounter "i8254" frequency 1193182 Hz quality 0 CPU: AMD Opteron(tm) Processor 248 (2191.53-MHz K8-class CPU) Origin = "AuthenticAMD" Id = 0xf5a Stepping = 10 Features=0x78bfbff AMD Features=0xe0500800 real memory = 2147418112 (2047 MB) avail memory = 2061656064 (1966 MB) ACPI APIC Table: FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs cpu0 (BSP): APIC ID: 0 cpu1 (AP): APIC ID: 1 MADT: Forcing active-low polarity and level trigger for SCI ioapic0 irqs 0-23 on motherboard acpi0: on motherboard acpi0: Power Button (fixed) Timecounter "ACPI-safe" frequency 3579545 Hz quality 1000 acpi_timer0: <24-bit timer at 3.579545MHz> port 0x5008-0x500b on acpi0 cpu0: on acpi0 acpi_throttle0: on cpu0 cpu1: on acpi0 pcib0: port 0xcf8-0xcff on acpi0 pci0: on pcib0 agp0: mem 0xf0000000-0xf7ffffff at device 0.0 on pci0 pcib1: at device 1.0 on pci0 pci2: on pcib1 pci2: at device 0.0 (no driver attached) pci2: at device 0.1 (no driver attached) pcib2: at device 6.0 on pci0 pci1: on pcib2 ohci0: mem 0xff4fd000-0xff4fdfff irq 19 at device 0.0 on pci1 usb0: OHCI version 1.0, legacy support usb0: SMM does not respond, resetting usb0: on ohci0 usb0: USB revision 1.0 uhub0: AMD OHCI root hub, class 9/0, rev 1.00/1.00, addr 1 uhub0: 3 ports with 3 removable, self powered ohci1: mem 0xff4fe000-0xff4fefff irq 19 at device 0.1 on pci1 usb1: OHCI version 1.0, legacy support usb1: SMM does not respond, resetting usb1: on ohci1 usb1: USB revision 1.0 uhub1: AMD OHCI root hub, class 9/0, rev 1.00/1.00, addr 1 uhub1: 3 ports with 3 removable, self powered em0: port 0x8c00-0x8c3f mem 0xff4a0000-0xff4 bffff,0xff4c0000-0xff4dffff irq 18 at device 3.0 on pci1 em0: Ethernet address: 00:e0:81:2c:0e:4e em0: Speed:N/A Duplex:N/A atapci0: port 0x9c00-0x9c0f,0xa000-0xa003,0xa400-0xa407,0xa800-0xa803,0 xac00-0xac07 mem 0xff4ffc00-0xff4fffff irq 19 at device 5.0 on pci1 ata2: channel #0 on atapci0 ata3: channel #1 on atapci0 ata4: channel #2 on atapci0 ata5: channel #3 on atapci0 pci1: at device 10.0 (no driver attached) uhci0: port 0x9400-0x941f irq 17 at device 11.0 on pci1 usb2: on uhci0 usb2: USB revision 1.0 uhub2: VIA UHCI root hub, class 9/0, rev 1.00/1.00, addr 1 uhub2: 2 ports with 2 removable, self powered uhci1: port 0x9800-0x981f irq 18 at device 11.1 on pci1 usb3: on uhci1 usb3: USB revision 1.0 uhub3: VIA UHCI root hub, class 9/0, rev 1.00/1.00, addr 1 uhub3: 2 ports with 2 removable, self powered ehci0: mem 0xff4ff800-0xff4ff8ff irq 19 at device 11.2 on pci1 usb4: EHCI version 1.0 usb4: companion controllers, 2 ports each: usb2 usb3 usb4: on ehci0 usb4: USB revision 2.0 uhub4: VIA EHCI root hub, class 9/0, rev 2.00/1.00, addr 1 uhub4: 4 ports with 4 removable, self powered isab0: at device 7.0 on pci0 isa0: on isab0 atapci1: port 0xffa0-0xffaf,0x376,0x170-0x177,0x3f6,0x1f0-0x1f7 at devi ce 7.1 on pci0 ata0: channel #0 on atapci1 ata1: channel #1 on atapci1 pci0: at device 7.2 (no driver attached) pci0: at device 7.3 (no driver attached) pci0: at device 7.5 (no driver attached) acpi_button0: on acpi0 sio0: configured irq 4 not in bitmap of probed irqs 0 sio0: port may not be enabled sio0: <16550A-compatible COM port> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0 sio0: type 16550A sio1: configured irq 3 not in bitmap of probed irqs 0 sio1: port may not be enabled sio1: <16550A-compatible COM port> port 0x2f8-0x2ff irq 3 on acpi0 sio1: type 16550A fdc0: port 0x3f7,0x3f0-0x3f5 irq 6 drq 2 on acpi0 ppc0: port 0x378-0x37f irq 7 on acpi0 ppc0: Generic chipset (NIBBLE-only) in COMPATIBLE mode ppbus0: on ppc0 plip0: on ppbus0 lpt0: on ppbus0 lpt0: Interrupt-driven port ppi0: on ppbus0 orm0: at iomem 0xd0000-0xd47ff,0xc0000-0xcffff on isa0 atkbdc0: at port 0x64,0x60 on isa0 sc0: at flags 0x100 on isa0 sc0: VGA <16 virtual consoles, flags=0x300> vga0: at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0 ums0: Logitech Trackball, rev 1.10/2.20, addr 2, iclass 3/1 ums0: 3 buttons and Z dir. uhub5: PI Engineering Kinesis Keyboard Hub, class 9/0, rev 1.10/3.20, addr 2 uhub5: 4 ports with 2 removable, bus powered ukbd0: P.I. Engineering product 0x0007, rev 1.10/3.20, addr 3, iclass 3/1 kbd0 at ukbd0 uhid0: P.I. Engineering product 0x0007, rev 1.10/3.20, addr 3, iclass 3/1 ums1: Microsoft Microsoft Wheel Mouse Optical\M-., rev 1.10/1.21, addr 2, iclass 3/1 ums1: 3 buttons and Z dir. Timecounters tick every 1.000 msec em0: Link is up 1000 Mbps Full Duplex ad0: 114473MB [232581/16/63] at ata0-master UDMA100 acd0: DVDR at ata1-slave PIO4 ad4: 114473MB [232581/16/63] at ata2-master SATA150 ad6: 114473MB [232581/16/63] at ata3-master SATA150 ar0: 228942MB [29186/255/63] status: READY subdisks: disk0 READY on ad4 at ata2-master disk1 READY on ad6 at ata3-master SMP: AP CPU #1 Launched! Mounting root from ufs:/dev/ad0s1a WARNING: / was not properly dismounted WARNING: /usr was not properly dismounted WARNING: /var was not properly dismounted WARNING: /mysql was not properly dismounted em0: Link is up 1000 Mbps Full Duplex Accounting enabled Accounting suspended drm0: port 0xb800-0xb8ff mem 0xff5f0000-0xff5fffff,0xe0000000-0xe7ffffff irq 16 at device 0.0 on pci2 info: [drm] AGP at 0xf0000000 128MB info: [drm] Initialized radeon 1.11.0 20020828 on minor 0 info: [drm] Loading R200 Microcode