From owner-freebsd-hackers@FreeBSD.ORG Thu Apr 16 15:33:41 2009 Return-Path: Delivered-To: freebsd-hackers@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 0F1611065686 for ; Thu, 16 Apr 2009 15:33:41 +0000 (UTC) (envelope-from deeptech71@gmail.com) Received: from mail-fx0-f167.google.com (mail-fx0-f167.google.com [209.85.220.167]) by mx1.freebsd.org (Postfix) with ESMTP id 3D6E28FC12 for ; Thu, 16 Apr 2009 15:33:39 +0000 (UTC) (envelope-from deeptech71@gmail.com) Received: by fxm11 with SMTP id 11so495905fxm.43 for ; Thu, 16 Apr 2009 08:33:39 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:received:received:message-id:date:from :user-agent:mime-version:to:subject:content-type :content-transfer-encoding; bh=ybuhNFCAmpYMEep6arxnR9ytoZUyetDMtvwplW5Sl/M=; b=u93tC1OO9hOGeqrtJTLQcA03A9UYVs6bEiRASkr/foeEAsXCRe3Lw9LfwsXJ7Hwo3+ Y6k3asBfns/6Q0jNpsgR/r7uWMoFWk7OuO2QFCjTgiBji5FwlyB5Lv8be+0xRfiXYLIy Xor7vM/51GL3+OiuPMgoBRio08owzbWN8NX6k= DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=message-id:date:from:user-agent:mime-version:to:subject :content-type:content-transfer-encoding; b=hblpffryeKqW1u8BiELBHHqOKdJxntI2w+3vOLWKXwySx8JZh8JHFBHzaPgr7mDd0C c//jYCU2pFDckXBusMVCKYeDjWdq1pCRfwDBBPfuasFC8em5w34QgqvGW0c4LAr7Tqx3 3xGso9FTXB44pc6nimqZMFKCkX375t5GdmtZk= Received: by 10.103.244.4 with SMTP id w4mr800306mur.90.1239894214306; Thu, 16 Apr 2009 08:03:34 -0700 (PDT) Received: from ?157.181.96.136? (quark.teteny.elte.hu [157.181.96.136]) by mx.google.com with ESMTPS id 23sm2709066mum.53.2009.04.16.08.03.33 (version=SSLv3 cipher=RC4-MD5); Thu, 16 Apr 2009 08:03:33 -0700 (PDT) Message-ID: <49E74917.808@gmail.com> Date: Thu, 16 Apr 2009 17:04:55 +0200 From: deeptech71@gmail.com User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.1.21) Gecko/20090303 SeaMonkey/1.1.15 MIME-Version: 1.0 To: freebsd-hackers@freebsd.org Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Subject: Re: diagnosing freezes (DRI?) X-BeenThere: freebsd-hackers@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Technical Discussions relating to FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 16 Apr 2009 15:33:41 -0000 I can reliably (~40%) reproduce a freeze, which I think is related. Using the GENERIC debug kernel built from SVN HEAD: # cd /usr/obj/usr/src/sys/GENERIC/ # kgdb kernel.debug /var/crash/vmcore.0 GNU gdb 6.1.1 [FreeBSD] Copyright 2004 Free Software Foundation, Inc. GDB is free software, covered by the GNU General Public License, and you are welcome to change it and/or 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. This GDB was configured as "i386-marcel-freebsd"... Unread portion of the kernel message buffer: <118>Apr 16 04:22:24 syslogd: exiting on signal 15 Waiting (max 60 seconds) for system process `vnlru' to stop...done Waiting (max 60 seconds) for system process `bufdaemon' to stop...done Wai tSiynngc i(nmga xd is6k0s ,s evcnoonddess) rfeomra isnyisntge.m. .pr0o cess `syncer' to stop...0 done All buffers synced. Copyright (c) 1992-2009 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 is a registered trademark of The FreeBSD Foundation. FreeBSD 8.0-CURRENT #0 r191101: Wed Apr 15 17:29:58 UTC 2009 devhc@:/usr/obj/usr/src/sys/GENERIC WARNING: WITNESS option enabled, expect reduced performance. Timecounter "i8254" frequency 1193182 Hz quality 0 CPU: Intel(R) Pentium(R) 4 CPU 2.80GHz (2798.67-MHz 686-class CPU) Origin = "GenuineIntel" Id = 0xf29 Stepping = 9 Features=0xbfebfbff Features2=0x4400 Logical CPUs per core: 2 real memory = 536870912 (512 MB) avail memory = 506023936 (482 MB) ACPI APIC Table: FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs cpu0 (BSP): APIC ID: 0 cpu1 (AP/HT): APIC ID: 1 ioapic0 irqs 0-23 on motherboard kbd1 at kbdmux0 acpi0: on motherboard acpi0: [ITHREAD] acpi0: Power Button (fixed) acpi0: reservation of 0, a0000 (3) failed acpi0: reservation of 100000, 1fef0000 (3) failed Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000 acpi_timer0: <24-bit timer at 3.579545MHz> port 0x808-0x80b on acpi0 pcib0: port 0xcf8-0xcff on acpi0 pci0: on pcib0 agp0: on hostb0 pcib1: at device 1.0 on pci0 pci1: on pcib1 vgapci0: port 0xd000-0xd0ff mem 0xd0000000-0xdfffffff,0xfbee0000-0xfbeeffff irq 16 at device 0.0 on pci1 vgapci1: mem 0xe0000000-0xefffffff,0xfbef0000-0xfbefffff at device 0.1 on pci1 uhci0: port 0xc880-0xc89f irq 16 at device 29.0 on pci0 uhci0: [ITHREAD] uhci0: LegSup = 0x2030 usbus0: on uhci0 uhci1: port 0xcc00-0xcc1f irq 19 at device 29.1 on pci0 uhci1: [ITHREAD] uhci1: LegSup = 0x2030 usbus1: on uhci1 ehci0: mem 0xfbdffc00-0xfbdfffff irq 23 at device 29.7 on pci0 ehci0: [ITHREAD] usbus2: EHCI version 1.0 usbus2: on ehci0 pcib2: at device 30.0 on pci0 pci2: on pcib2 skc0: <3Com 3C940 Gigabit Ethernet> port 0xe800-0xe8ff mem 0xfbffc000-0xfbffffff irq 22 at device 5.0 on pci2 skc0: 3Com Gigabit LOM (3C940) rev. (0x1) sk0: on skc0 sk0: Ethernet address: 00:0e:a6:35:15:91 miibus0: on sk0 e1000phy0: PHY 0 on miibus0 e1000phy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseTX-FDX, auto skc0: [ITHREAD] pcm0: port 0xec00-0xec3f irq 20 at device 12.0 on pci2 pcm0: pcm0: [ITHREAD] pcm0: isab0: at device 31.0 on pci0 isa0: on isab0 atapci0: port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xfc00-0xfc0f at device 31.1 on pci0 ata0: on atapci0 ata0: [ITHREAD] ata1: on atapci0 ata1: [ITHREAD] pci0: at device 31.3 (no driver attached) acpi_button0: on acpi0 atrtc0: port 0x70-0x71 irq 8 on acpi0 atkbdc0: port 0x60,0x64 irq 1 on acpi0 atkbd0: irq 1 on atkbdc0 kbd0 at atkbd0 atkbd0: [GIANT-LOCKED] atkbd0: [ITHREAD] uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0 uart0: [FILTER] uart1: <16550 or compatible> port 0x2f8-0x2ff irq 3 on acpi0 uart1: [FILTER] ppc0: port 0x378-0x37f,0x778-0x77b irq 7 drq 3 on acpi0 ppc0: SMC-like chipset (ECP/EPP/PS2/NIBBLE) in COMPATIBLE mode ppc0: FIFO with 16/16/9 bytes threshold ppc0: [ITHREAD] ppbus0: on ppc0 plip0: on ppbus0 plip0: [ITHREAD] lpt0: on ppbus0 lpt0: [ITHREAD] lpt0: Interrupt-driven port ppi0: on ppbus0 cpu0: on acpi0 p4tcc0: on cpu0 cpu1: on acpi0 p4tcc1: on cpu1 pmtimer0 on isa0 orm0: at iomem 0xc0000-0xccfff pnpid ORM0000 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 Timecounters tick every 1.000 msec usbus0: 12Mbps Full Speed USB v1.0 usbus1: 12Mbps Full Speed USB v1.0 usbus2: 480Mbps High Speed USB v2.0 ad0: 78167MB at ata0-master UDMA100 ugen0.1: at usbus0 uhub0: on usbus0 ugen1.1: at usbus1 uhub1: on usbus1 ugen2.1: at usbus2 uhub2: on usbus2 acd0: DMA limited to UDMA33, controller found non-ATA66 cable GEOM: ad0s1: geometry does not match label (255h,63s != 16h,63s). acd0: DVDR at ata1-master UDMA33 SMP: AP CPU #1 Launched! WARNING: WITNESS option enabled, expect reduced performance. GEOM_LABEL: Label for provider ad0s2 is msdosfs/WINXP. GEOM_LABEL: Label for provider ad0s3 is ntfs/STORAGE. GEOM_LABEL: Label for provider ad0s1a is ufsid/49cf0dead38cbdfd. Root mount waiting for: usbus2 usbus1 usbus0 uhub0: 2 ports with 2 removable, self powered uhub1: 2 ports with 2 removable, self powered Root mount waiting for: usbus2 uhub2: 4 ports with 4 removable, self powered Root mount waiting for: usbus2 Trying to mount root from ufs:/dev/ad0s1a <118>Entropy harvesting: <118> interrupts <118> ethernet <118> point_to_point <118> kickstart <118>. GEOM_LABEL: Label ufsid/49cf0dead38cbdfd removed. <118>/dev/ad0s1a: FILE SYSTEM CLEAN; SKIPPING CHECKS <118>/dev/ad0s1a: clean, 576271 free (53999 frags, 65284 blocks, 1.3% fragmentation) GEOM_LABEL: Label for provider ad0s1a is ufsid/49cf0dead38cbdfd. ugen0.2: at usbus0 GEOM_LABEL: Label ufsid/49cf0dead38cbdfd removed. ums0: on usbus0 ums0: 5 buttons and [XYZ] coordinates ID=1 GEOM_LABEL: Label msdosfs/WINXP removed. <118>/etc/rc: WARNING: $hostname is not set -- see rc.conf(5). <118>Starting Network: sk0. <118>Starting Network: lo0. <118>Apr 16 04:23:08 syslogd: bind: Can't assign requested address <118>Apr 16 04:23:08 syslogd: bind: Can't assign requested address <118>syslogd: <118>child pid 546 exited with return code 1 <118> <118>/etc/rc: WARNING: failed to start syslogd <118>moused: <118>unable to open /dev/psm0: No such file or directory <118> <118>/etc/rc: WARNING: $dbus_enable is not set properly - see rc.conf(5). <118>Starting dbus. <118>Starting hald. <118>Configuring syscons: <118> blanktime <118>. <118> <118>Thu Apr 16 04:23:10 UTC 2009 drm0: on vgapci0 vgapci0: child drm0 requested pci_enable_busmaster info: [drm] AGP at 0xf0000000 128MB info: [drm] Initialized radeon 1.29.0 20080528 info: [drm] Setting GART location based on new memory map info: [drm] Loading R300 Microcode info: [drm] Num pipes: 1 info: [drm] writeback test succeeded in 1 usecs drm0: [ITHREAD] lock order reversal: 1st 0xc31a5270 bufwait (bufwait) @ /usr/src/sys/kern/vfs_bio.c:2549 2nd 0xc39a3400 dirhash (dirhash) @ /usr/src/sys/ufs/ufs/ufs_dirhash.c:275 KDB: stack backtrace: db_trace_self_wrapper(c0c2ebcc,d644b860,c0896895,c088879b,c0c319b1,...) at db_trace_self_wrapper+0x26 kdb_backtrace(c088879b,c0c319b1,c3524a80,c3527e18,d644b8bc,...) at kdb_backtrace+0x29 _witness_debugger(c0c319b1,c39a3400,c0c50e61,c3527e18,c0c50afa,...) at _witness_debugger+0x25 witness_checkorder(c39a3400,9,c0c50afa,113,0,...) at witness_checkorder+0x839 _sx_xlock(c39a3400,0,c0c50afa,113,c3b4c7c0,...) at _sx_xlock+0x85 ufsdirhash_acquire(c31a5210,d644b9d4,128,cec0baf0,d644b98c,...) at ufsdirhash_acquire+0x35 ufsdirhash_add(c3b4c7c0,d644b9d4,af0,d644b978,d644b97c,...) at ufsdirhash_add+0x13 ufs_direnter(c3b5ca78,c3df4860,d644b9d4,d644bbe0,0,...) at ufs_direnter+0x729 ufs_makeinode(d644bbe0,d644bb4c,d644bc04,d644bb1c,c0b70e35,...) at ufs_makeinode+0x519 ufs_create(d644bc04,d644bc18,0,d644bb4c,d644bbb4,...) at ufs_create+0x30 VOP_CREATE_APV(c0d2fc20,d644bc04,68,1a4,c39a1aac,...) at VOP_CREATE_APV+0xa5 uipc_bind(c3dc3000,c3741b00,c3c80230,d644bc60,c08c0049,...) at uipc_bind+0x30e sobind(c3dc3000,c3741b00,c3c80230,1a,c38d5658,...) at sobind+0x23 kern_bind(c3c80230,3,c3741b00,c3741b00,80906a4,...) at kern_bind+0x79 bind(c3c80230,d644bcf8,c,c0c321f2,c0d0ed20,...) at bind+0x46 syscall(d644bd38) at syscall+0x2a3 Xint0x80_syscall() at Xint0x80_syscall+0x20 --- syscall (104, FreeBSD ELF32, bind), eip = 0x2818a983, esp = 0xbfbfe96c, ebp = 0xbfbfea68 --- <118>Apr 16 04:24:28 su: devhc to root on /dev/pts/1 Kernel page fault with the following non-sleepable locks held: exclusive sleep mutex drmdev (drmdev) r = 0 (0xc373f860) locked @ /usr/src/sys/modules/drm/drm/../../../dev/drm/drm_drv.c:777 KDB: stack backtrace: db_trace_self_wrapper(c0c2ebcc,d67d4980,c0896895,c3d40457,309,...) at db_trace_self_wrapper+0x26 kdb_backtrace(c3d40457,309,ffffffff,c0eba8c4,d67d49b8,...) at kdb_backtrace+0x29 _witness_debugger(c0c30f5d,d67d49cc,4,1,0,...) at _witness_debugger+0x25 witness_warn(5,0,c0c62807,0,c42087ec,...) at witness_warn+0x1fd trap(d67d4a58) at trap+0x152 calltrap() at calltrap+0x6 --- trap 0xc, eip = 0xc0b611b6, esp = 0xd67d4a98, ebp = 0xd67d4b48 --- slow_copyin(c373f800,c4103300,c42e64e0,d67d4b64,0,...) at slow_copyin+0x6 radeon_cp_texture(c373f800,c42e64e0,c4103300,309,c0c26218,...) at radeon_cp_texture+0x199 drm_ioctl(c39d4e00,c018644e,c42e64e0,3,c40afaf0,...) at drm_ioctl+0x356 devfs_ioctl_f(c38c7150,c018644e,c42e64e0,c38d4700,c40afaf0,...) at devfs_ioctl_f+0xf8 kern_ioctl(c40afaf0,24,c018644e,c42e64e0,18901f0,...) at kern_ioctl+0x1dd ioctl(c40afaf0,d67d4cf8,c,c0c65279,c0d0e870,...) at ioctl+0x134 syscall(d67d4d38) at syscall+0x2a3 Xint0x80_syscall() at Xint0x80_syscall+0x20 --- syscall (54, FreeBSD ELF32, ioctl), eip = 0x2834ec67, esp = 0xbfbf944c, ebp = 0xbfbf9468 --- Fatal trap 12: page fault while in kernel mode cpuid = 0; apic id = 00 fault virtual address = 0x3f561000 fault code = supervisor read, page not present instruction pointer = 0x20:0xc0b611b6 stack pointer = 0x28:0xd67d4a98 frame pointer = 0x28:0xd67d4b48 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 = 1094 (initial thread) trap number = 12 panic: page fault cpuid = 0 Uptime: 4m53s Physical memory: 494 MB Dumping 107 MB: 92 76 60 44 28 12 Reading symbols from /boot/kernel.GENERIC.r191101.debug/snd_es137x.ko...Reading symbols from /boot/kernel.GENERIC.r191101.debug/snd_es137x.ko.symbols...done. done. Loaded symbols for /boot/kernel.GENERIC.r191101.debug/snd_es137x.ko Reading symbols from /boot/kernel.GENERIC.r191101.debug/sound.ko...Reading symbols from /boot/kernel.GENERIC.r191101.debug/sound.ko.symbols...done. done. Loaded symbols for /boot/kernel.GENERIC.r191101.debug/sound.ko Reading symbols from /boot/kernel.GENERIC.r191101.debug/radeon.ko...Reading symbols from /boot/kernel.GENERIC.r191101.debug/radeon.ko.symbols...done. done. Loaded symbols for /boot/kernel.GENERIC.r191101.debug/radeon.ko Reading symbols from /boot/kernel.GENERIC.r191101.debug/drm.ko...Reading symbols from /boot/kernel.GENERIC.r191101.debug/drm.ko.symbols...done. done. Loaded symbols for /boot/kernel.GENERIC.r191101.debug/drm.ko #0 doadump () at pcpu.h:246 246 __asm __volatile("movl %%fs:0,%0" : "=r" (td)); (kgdb) backtrace #0 doadump () at pcpu.h:246 #1 0xc085712e in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:420 #2 0xc0857402 in panic (fmt=Variable "fmt" is not available. ) at /usr/src/sys/kern/kern_shutdown.c:576 #3 0xc0b63323 in trap_fatal (frame=0xd67d4a58, eva=1062604800) at /usr/src/sys/i386/i386/trap.c:926 #4 0xc0b63c20 in trap (frame=0xd67d4a58) at /usr/src/sys/i386/i386/trap.c:318 #5 0xc0b47b5b in calltrap () at /usr/src/sys/i386/i386/exception.s:165 #6 0xc0b611b6 in slow_copyin () at /usr/src/sys/i386/i386/support.s:887 Previous frame inner to this frame (corrupt stack?) (kgdb) list *0xc0b611b6 0xc0b611b6 is at /usr/src/sys/i386/i386/support.s:888. 883 slow_copyin: 884 #endif 885 movb %cl,%al 886 shrl $2,%ecx /* copy longword-wise */ 887 cld 888 rep 889 movsl 890 movb %al,%cl 891 andb $3,%cl /* copy remaining bytes*/ 892 rep (kgdb) OMG, ASM! I don't what this assembly code means or how to debug it. So what now? I can run commands on request. Or should I package the whole vmcore & kernel and upload/send it somewhere for inspection (tell me exactly which files)? 3 more things: The command ddb capture -M /var/crash/vmcore.0 print printed only a few ugly characters. This kernel output really looks bad: Wai tSiynngc i(nmga xd is6k0s ,s evcnoonddess) rfeomra isnyisntge.m. .pr0o cess `syncer' to stop...0 done What's the explanation to: Previous frame inner to this frame (corrupt stack?) ?