Skip site navigation (1)Skip section navigation (2)
Date:      Fri, 16 Jul 2004 15:49:57 +0200
From:      Jilles Tjoelker <jilles@stack.nl>
To:        freebsd-current@freebsd.org
Cc:        unix@stack.nl
Subject:   System call recvfrom returning with Giant held
Message-ID:  <20040716134956.GA11978@stack.nl>

next in thread | raw e-mail | index | archive | help
Hello,

One of our 5.2.1R machines panics reproducibly when using mplayer on
the following URL:

rtsp://demand1.stream.aol.com/wb/gl/wbonline/real/wbmovies/catwoman/trailer/trailer_500.rm

This was done on a remote X display.

Although uname shows it as 5.2.1-RELEASE-p8, the linux module has been
recompiled with the -p9 patch.

Script started on Fri Jul 16 15:02:09 2004
# ls -F
bounds		info.16		info.20		info.24		info.28
info.13		info.17		info.21		info.25		kernel.debug@
info.14		info.18		info.22		info.26		minfree
info.15		info.19		info.23		info.27		vmcore.28
# cp /usr/obj/usr/src/sys/TURTLE/kernel.debug kernel.debug.28
# gdb -k kernel.debug.28 vmcore.28
GNU gdb 5.2.1 (FreeBSD)
Copyright 2002 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-unknown-freebsd"...
panic: witness_warn
panic messages:
---
panic: witness_warn
cpuid = 0; 
boot() called on cpu#0

syncing disks, buffers remaining... 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 
giving up on 1099 buffers
Uptime: 10m39s
Dumping 1023 MB
 16 32 48 64 80 96 112 128 144 160 176 192 208 224 240 256 272 288 304 320 336 352 368 384 400 416 432 448 464 480 496 512 528 544 560 576 592 608 624 640 656 672 688 704 720 736 752 768 784 800 816 832 848 864 880 896 912 928 944 960 976 992 1008
---
Reading symbols from /usr/obj/usr/src/sys/TURTLE/modules/usr/src/sys/modules/fdescfs/fdescfs.ko.debug...done.
Loaded symbols for /usr/obj/usr/src/sys/TURTLE/modules/usr/src/sys/modules/fdescfs/fdescfs.ko.debug
Reading symbols from /usr/obj/usr/src/sys/TURTLE/modules/usr/src/sys/modules/linux/linux.ko.debug...done.
Loaded symbols for /usr/obj/usr/src/sys/TURTLE/modules/usr/src/sys/modules/linux/linux.ko.debug
#0  doadump () at /usr/src/sys/kern/kern_shutdown.c:240
240		dumping++;
(kgdb) bt full
#0  doadump () at /usr/src/sys/kern/kern_shutdown.c:240
No locals.
#1  0xc050491b in boot (howto=256) at /usr/src/sys/kern/kern_shutdown.c:372
No locals.
#2  0xc0504d1d in panic () at /usr/src/sys/kern/kern_shutdown.c:550
	td = (struct thread *) 0xc67d9140
	bootopt = 256
	newpanic = 1
	ap = 0xe5e38ccc "ّ\214مه\001"
	buf = "witness_warn", '\0' <repeats 243 times>
#3  0xc052cc24 in witness_warn (flags=2, lock=0x0, 
    fmt=0xc06dcc00 "System call %s returning")
    at /usr/src/sys/kern/subr_witness.c:1075
	lle = (struct lock_list_entry *) 0x0
	lock1 = (struct lock_instance *) 0xc07450ac
	i = -1
	n = 1
#4  0xc068512a in syscall (frame=
      {tf_fs = 47, tf_es = 47, tf_ds = 47, tf_edi = 140976128, tf_esi = 0, tf_ebp = -1077948072, tf_isp = -438071948, tf_ebx = 685057748, tf_edx = 8, tf_ecx = 8, tf_eax = 22, tf_trapno = 22, tf_err = 2, tf_eip = 687439615, tf_cs = 31, tf_eflags = 2097735, tf_esp = -1077948116, tf_ss = 47})
    at /usr/src/sys/i386/i386/trap.c:1079
	params = 0xbfbfd130---Can't read userspace from dump, or kernel process---

(kgdb) frame 3
#3  0xc052cc24 in witness_warn (flags=2, lock=0x0, 
    fmt=0xc06dcc00 "System call %s returning")
    at /usr/src/sys/kern/subr_witness.c:1075
1075			panic("witness_warn");
(kgdb) p *lock1
$1 = {li_lock = 0xc071bec0, 
  li_file = 0xc06c769f "/usr/src/sys/kern/uipc_syscalls.c", li_line = 930, 
  li_flags = 65536}
(kgdb) p *(lock1->li_lock)
$2 = {lo_class = 0xc06f413c, lo_name = 0xc06c1358 "Giant", 
  lo_type = 0xc06c1358 "Giant", lo_flags = 720896, lo_list = {
    tqe_next = 0xc071be80, tqe_prev = 0xc071f210}, lo_witness = 0xc0722568}
(kgdb) # 
# 
# ps axl kernel.debug.28 vmcore.28     ### output somewhat stripped
  UID   PID  PPID CPU PRI NI   VSZ  RSS MWCHAN STAT  TT       TIME COMMAND
...
  103   738   728 327698  20  0   808    0 pause  Ds   #C:    0:00.11  (ksh)
  103   919   738 327698   4  0 25340    0 -      R+   #C:    0:30.43  (mplayer)
  103   920   919 327698 -68  0 20788    0 -      R+   #C:    0:15.09  (mplayer)
...
    0     0     0 327698 -16  0     0    0 sched  DLs   ??    0:00.01  (swapper)
    0     1     0 327698   8  0   760    0 wait   DLs   ??    0:00.04  (init)
    0     2     0 327698  -8  0     0    0 -      DL    ??    0:00.06  (g_event)
    0     3     0 327698  -8  0     0    0 -      DL    ??    0:01.10  (g_up)
    0     4     0 327698  -8  0     0    0 -      DL    ??    0:01.05  (g_down)
    0     5     0 327698   8  0     0    0 tqthr  DL    ??    0:00.00  (taskqueue)
    0     6     0 327698 -84  0     0    0 actask DL    ??    0:00.00  (acpi_task0
    0     7     0 327698 -84  0     0    0 actask DL    ??    0:00.00  (acpi_task1
    0     8     0 327698 -84  0     0    0 actask DL    ??    0:00.00  (acpi_task2
    0     9     0 327698 -16  0     0    0 psleep DL    ??    0:00.00  (pagedaemon
    0    10     0 327698 -16  0     0    0 ktrace DL    ??    0:00.00  (ktrace)
    0    11     0 327698 -16  0     0    0 -      RL    ??    9:43.68  (idle: cpu1
    0    12     0 327698 -16  0     0    0 -      RL    ??    9:56.71  (idle: cpu0
    0    13     0 327698 -60  0     0    0 -      WL    ??    0:00.06  (irq1: atkb
    0    14     0 327698 -60  0     0    0 -      RL    ??    0:00.00  (irq3: sio1
    0    15     0 327698 -60  0     0    0 -      RL    ??    0:00.00  (irq4: sio0
    0    16     0 327698 -21  0     0    0 -      RL    ??    0:00.00  (irq5:)
    0    17     0 327698 -64  0     0    0 -      WL    ??    0:00.00  (irq6: fdc0
    0    18     0 327698 -21  0     0    0 -      RL    ??    0:00.00  (irq7:)
    0    19     0 327698 -84  0     0    0 -      RL    ??    0:00.00  (irq8: rtc)
    0    20     0 327698 -52  0     0    0 -      WL    ??    0:00.12  (irq9: acpi
    0    21     0 327698 -21  0     0    0 -      RL    ??    0:00.00  (irq10:)
    0    22     0 327698 -21  0     0    0 -      RL    ??    0:00.00  (irq11:)
    0    23     0 327698 -60  0     0    0 -      WL    ??    0:00.01  (irq12: psm
    0    24     0 327698 -21  0     0    0 -      RL    ??    0:00.00  (irq13:)
    0    25     0 327698 -21  0     0    0 -      RL    ??    0:00.00  (irq14:)
    0    26     0 327698 -21  0     0    0 -      RL    ??    0:00.00  (irq15:)
    0    27     0 327698 -21  0     0    0 -      RL    ??    0:00.00  (irq16:)
    0    28     0 327698 -21  0     0    0 -      RL    ??    0:00.00  (irq17:)
    0    29     0 327698 -68  0     0    0 Giant  LL    ??    0:05.91  (irq18: xl0
    0    30     0 327698 -68  0     0    0 Giant  LL    ??    0:00.17  (irq19: xl1
    0    31     0 327698 -64  0     0    0 Giant  LL    ??    0:00.48  (irq20: ahc
    0    32     0 327698 -64  0     0    0 -      WL    ??    0:00.00  (irq21: ahc
    0    33     0 327698 -21  0     0    0 -      RL    ??    0:00.00  (irq22:)
    0    34     0 327698 -21  0     0    0 -      RL    ??    0:00.00  (irq23:)
    0    35     0 327698 -84  0     0    0 -      RL    ??    0:00.00  (irq0: clk)
    0    36     0 327698 -44  0     0    0 -      WL    ??    0:03.78  (swi1: net)
    0    37     0 327698 -48  0     0    0 Giant  LL    ??    0:03.85  (swi8: tty:
    0    38     0 327698 -32  0     0    0 -      RL    ??    0:00.00  (swi4: vm)
    0    39     0 327698  76  0     0    0 -      DL    ??    0:00.27  (random)
    0    40     0 327698 -24  0     0    0 -      RL    ??    0:00.00  (swi6:+)
    0    41     0 327698 -28  0     0    0 -      RL    ??    0:00.00  (swi5:+)
    0    42     0 327698 -20  0     0    0 -      WL    ??    0:00.00  (swi7: acpi
    0    43     0 327698 -40  0     0    0 -      RL    ??    0:00.00  (swi2: camn
    0    44     0 327698 -36  0     0    0 Giant  LL    ??    0:00.60  (swi3: camb
    0    45     0 327698 -20  0     0    0 -      RL    ??    0:00.00  (swi7: task
    0    46     0 327698 -48  0     0    0 -      WL    ??    0:00.00  (swi0: tty:
    0    47     0 327698  20  0     0    0 psleep DL    ??    0:00.00  (vmdaemon)
    0    48     0 327698 171  0     0    0 pgzero DL    ??    0:01.95  (pagezero)
    0    49     0 327698 -16  0     0    0 psleep DL    ??    0:00.01  (bufdaemon)
    0    50     0 327698  -4  0     0    0 vlruwt DL    ??    0:00.01  (vnlru)
    0    51     0 327698  20  0     0    0 syncer DL    ??    0:00.09  (syncer)
    0    52     0 327698   8  0     0    0 -      DL    ??    0:00.03  (nfsiod 0)
    0    53     0 327698   8  0     0    0 -      DL    ??    0:00.00  (nfsiod 1)
    0    54     0 327698   8  0     0    0 -      DL    ??    0:00.00  (nfsiod 2)
    0    55     0 327698   8  0     0    0 -      DL    ??    0:00.00  (nfsiod 3)
...
    0   357     1 327698  96  0  1352    0 -      Rs    ??    0:00.06  (syslogd)
    0   370     1 327698  96  0  4904    0 -      Rs    ??    0:00.43  (named)
    0   383     1 327698  96  0  1496    0 select Ds    ??    0:00.05  (rpcbind)
    0   459     1 327698  96  0  1460    0 select Ds    ??    0:00.02  (mountd)
    0   468     1 327698   4  0  1372    0 select Ds    ??    0:00.05  (nfsd)
    0   469   468 327698   4  0  1256    0 -      D     ??    0:00.00  (nfsd)
    0   470   468 327698   4  0  1256    0 -      D     ??    0:00.00  (nfsd)
    0   471   468 327698   4  0  1256    0 -      D     ??    0:00.00  (nfsd)
    0   472   468 327698   4  0  1256    0 -      D     ??    0:00.00  (nfsd)
    0   473   468 327698   4  0  1256    0 -      D     ??    0:00.00  (nfsd)
    0   474   468 327698   4  0  1256    0 -      D     ??    0:00.00  (nfsd)
    0   481     1 327698  96  0 263584    0 -      Rs    ??    0:00.00  (rpc.statd)
    0   486     1 327698  96  0  1612    0 select Ds    ??    0:00.01  (rpc.lockd)
    1   494   486 327698   4  0  1612    0 select D     ??    0:00.00  (rpc.lockd)
...
# dmesg -N kernel.debug.28 -M vmcore.28
Copyright (c) 1992-2004 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.2.1-RELEASE-p8 #28: Wed May 26 18:25:55 CEST 2004
    marcolz@turtle.stack.nl:/usr/obj/usr/src/sys/TURTLE
Preloaded elf kernel "/boot/kernel/kernel" at 0xc07fa000.
ACPI APIC Table: <PTLTD  	 APIC  >
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: AMD Athlon(tm) MP 2000+ (1666.74-MHz 686-class CPU)
  Origin = "AuthenticAMD"  Id = 0x662  Stepping = 2
  Features=0x383fbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR,SSE>
  AMD Features=0xc0480000<MP,AMIE,DSP,3DNow!>
real memory  = 1073217536 (1023 MB)
avail memory = 1037139968 (989 MB)
FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs
 cpu0 (BSP): APIC ID:  1
 cpu1 (AP): APIC ID:  0
ioapic0 <Version 1.1> irqs 0-23 on motherboard
Pentium Pro MTRR support enabled
acpi0: <PTLTD    RSDT  > on motherboard
pcibios: BIOS version 2.10
Using $PIR table, 14 entries at 0xc00fdee0
acpi0: Power Button (fixed)
acpi0: Sleep Button (fixed)
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x8008-0x800b on acpi0
acpi_cpu0: <CPU> on acpi0
acpi_cpu1: <CPU> on acpi0
acpi_button0: <Power Button> on acpi0
pcib0: <ACPI Host-PCI bridge> port 0x8080-0x80ff,0x8000-0x807f,0xcf8-0xcff iomem 0xd8000-0xdbfff on acpi0
pci0: <ACPI PCI bus> on pcib0
agp0: <AMD 762 host to AGP bridge> port 0x1810-0x1813 mem 0xf9300000-0xf9300fff,0xfa000000-0xfbffffff at device 0.0 on pci0
pcib1: <ACPI PCI-PCI bridge> at device 1.0 on pci0
pci1: <ACPI PCI bus> on pcib1
pci1: <display, VGA> at device 5.0 (no driver attached)
isab0: <PCI-ISA bridge> at device 7.0 on pci0
isa0: <ISA bus> on isab0
pci0: <mass storage, ATA> at device 7.1 (no driver attached)
pci0: <bridge, PCI-unknown> at device 7.3 (no driver attached)
ahc0: <Adaptec aic7899 Ultra160 SCSI adapter> port 0x1000-0x10ff mem 0xf8000000-0xf8000fff irq 20 at device 10.0 on pci0
aic7899: Ultra160 Wide Channel A, SCSI Id=7, 32/253 SCBs
ahc1: <Adaptec aic7899 Ultra160 SCSI adapter> port 0x1400-0x14ff mem 0xf8001000-0xf8001fff irq 21 at device 10.1 on pci0
aic7899: Ultra160 Wide Channel B, SCSI Id=7, 32/253 SCBs
pcib2: <ACPI PCI-PCI bridge> at device 16.0 on pci0
pci2: <ACPI PCI bus> on pcib2
xl0: <3Com 3c980C Fast Etherlink XL> port 0x2000-0x207f mem 0xf9001000-0xf900107f irq 18 at device 8.0 on pci2
xl0: Ethernet address: 00:e0:81:22:51:d8
miibus0: <MII bus> on xl0
ukphy0: <Generic IEEE 802.3u media interface> on miibus0
ukphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
xl1: <3Com 3c980C Fast Etherlink XL> port 0x2080-0x20ff mem 0xf9001400-0xf900147f irq 19 at device 9.0 on pci2
xl1: Ethernet address: 00:e0:81:22:51:d9
miibus1: <MII bus> on xl1
ukphy1: <Generic IEEE 802.3u media interface> on miibus1
ukphy1:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
atkbdc0: <Keyboard controller (i8042)> port 0x64,0x60 irq 1 on acpi0
atkbd0: <AT Keyboard> flags 0x1 irq 1 on atkbdc0
kbd0 at atkbd0
psm0: <PS/2 Mouse> irq 12 on atkbdc0
psm0: model IntelliMouse, device ID 3
sio0 port 0x3f8-0x3ff irq 4 on acpi0
sio0: type 16550A
sio1 port 0x2f8-0x2ff irq 3 on acpi0
sio1: type 16550A
fdc0: <Enhanced floppy controller (i82077, NE72065 or clone)> port 0x3f7,0x3f0-0x3f5 irq 6 drq 2 on acpi0
fdc0: FIFO enabled, 8 bytes threshold
fd0: <1440-KB 3.5" drive> on fdc0 drive 0
npx0: [FAST]
npx0: <math processor> on motherboard
npx0: INT 16 interface
orm0: <Option ROMs> at iomem 0xdc000-0xdffff,0xcd800-0xcdfff,0xc0000-0xc7fff on isa0
sc0: <System console> at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
Timecounters tick every 10.000 msec
ipfw2 initialized, divert disabled, rule-based forwarding enabled, default to accept, logging disabled
IPv6 packet filtering initialized, default to accept, logging disabled
Waiting 5 seconds for SCSI devices to settle
GEOM: create disk da0 dp=0xc673a450
da0 at ahc0 bus 0 target 6 lun 0
da0: <IBM IC35L018UWD210-0 S5CS> Fixed Direct Access SCSI-3 device 
da0: 160.000MB/s transfers (80.000MHz, offset 63, 16bit), Tagged Queueing Enabled
da0: 17501MB (35843670 512 byte sectors: 255H 63S/T 2231C)
SMP: AP CPU #1 Launched!
Mounting root from ufs:/dev/da0s1a
WARNING: / was not properly dismounted
Accounting enabled
System call recvfrom returning with the following locks held:
exclusive sleep mutex Giant r = 0 (0xc071bec0) locked @ /usr/src/sys/kern/uipc_syscalls.c:930
panic: witness_warn
cpuid = 0; 
boot() called on cpu#0

syncing disks, buffers remaining... 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 2005 
giving up on 1099 buffers
Uptime: 10m39s
Dumping 1023 MB
 16 32 48 64 80 96 112 128 144 160 176 192 208 224 240 256 272 288 304 320 336 352 368 384 400 416 432 448 464 480 496 512 528 544 560 576 592 608 624 640 656 672 688 704 720 736 752 768 784 800 816 832 848 864 880 896 912 928 944 960 976 992 1008
# uname -a
FreeBSD turtle.stack.nl 5.2.1-RELEASE-p8 FreeBSD 5.2.1-RELEASE-p8 #28: Wed May 26 18:25:55 CEST 2004     marcolz@turtle.stack.nl:/usr/obj/usr/src/sys/TURTLE  i386
# 
Script done on Fri Jul 16 15:36:42 2004

-- 
Jilles Tjoelker



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20040716134956.GA11978>