misc/92395: truss does not work properly, procfs looks like it's limited to 128 elements

Thu Jan 26 13:50:03 PST 2006

>Number:         92395
>Category:       misc
>Synopsis:       truss does not work properly, procfs looks like it's limited to 128 elements
>Confidential:   no
>Severity:       non-critical
>Priority:       low
>Responsible:    freebsd-bugs
>State:          open
>Quarter:        
>Keywords:       
>Date-Required:
>Class:          sw-bug
>Submitter-Id:   current-users
>Arrival-Date:   Thu Jan 26 21:50:02 GMT 2006
>Closed-Date:
>Last-Modified:
>Originator:     Patrick Proniewski
>Release:        FreeBSD 5.4-RELEASE-p8 #0
>Organization:
Université Lyon 2
>Environment:
FreeBSD example.com 5.4-RELEASE-p8 FreeBSD 5.4-RELEASE-p8 #0: Sun Oct 16 17:12:30 CEST 2005     patpro at example.com:/usr/obj/usr/src/sys/PATPRO-20050829  i386

>Description:
The truss command is unable to function correctly on my system:
Bellow, I use the `ls` command as an example, other commands used with truss yield to the same results.

- some times it will return: 
$ truss ls
truss: cannot open /proc/4509/mem: No such file or directory  (This one it reproductible with `ktrace truss ls`)

such processes are stuck in state "D" : Marks a process in disk (or other short term, uninterruptible) wait.

patpro    57096     1  0.0  0.0 ttyp1    10:13PM D    ls
patpro    57125     1  0.0  0.0 ttyp1    10:13PM D    ls -al
patpro    57446     1  0.0  0.0 ttyp1    10:15PM D    uname

- some times it will return:
$ truss ls
truss: PIOCWAIT: Input/output error (This one won't happen when the command is launched as `ktrace truss ls`)

of course, PROCFS is mounted (at boot time):

$ df procfs
Filesystem 1K-blocks Used Avail Capacity  Mounted on
procfs                      4      4       0      100%           /proc

But this procfs behaves strangely too. It seems unable to contain more than 128 items : 

$ ls -1 /proc/ | wc -l
    128
$ ps aux | wc  -l
    207

Looks like a power of 2, to me. I think both problem might be related.

It has been mentioned on freebsd-questions, that it could be some sort of race condition between truss and the command it is supposed to monitor the activity of.
I can regain proper behaviour if I issue this type of command : 

$ truss `which ls`

instead of 

$ truss ls

`truss ls -al` gives good results most of the time, but not every times.

complete sysctl : http://boleskine.patpro.net/~patpro/sysctl.txt
kernel config : 
machine         i386
cpu             I686_CPU
ident           PATPRO-20050829

options         SCHED_4BSD
options         INET
options         FFS
options         SOFTUPDATES
options         UFS_ACL
options         UFS_DIRHASH
options         MD_ROOT
options         NFSCLIENT
options         NFSSERVER
options         NFS_ROOT
options         MSDOSFS
options         CD9660
options         PROCFS
options         PSEUDOFS
options         GEOM_GPT
options         COMPAT_43
options         COMPAT_FREEBSD4
options         SCSI_DELAY=15000
options         KTRACE
options         SYSVSHM
options         SYSVMSG
options         SYSVSEM
options         _KPOSIX_PRIORITY_SCHEDULING
options         KBD_INSTALL_CDEV
options         AHC_REG_PRETTY_PRINT
options         AHD_REG_PRETTY_PRINT
options         ADAPTIVE_GIANT
options         ALTQ
options         ALTQ_CBQ
options         ALTQ_RED
options         ALTQ_RIO
options         ALTQ_HFSC
options         ALTQ_PRIQ
options         ALTQ_NOPCC
options         SMP
options         MPTABLE_FORCE_HTT

device          apic
device          isa
device          eisa
device          pci
device          fdc
device          ata
device          atadisk
device          ataraid
device          atapicd
device          atapifd
device          atapist
options         ATA_STATIC_ID
device          atkbdc
device          atkbd
device          psm
device          vga
device          splash
device          sc
device          agp
device          npx
device          pmtimer
device          sio
device          ppc
device          ppbus
device          ppi
device          em
device          miibus
device          fxp
device          ex
device          loop
device          mem
device          io
device          random
device          ether
device          tun
device          pty
device          md
device          bpf
device          uhci
device          ohci
device          ehci
device          usb
device          ugen
device          uhid
device          ukbd

hardware : 

Timecounter "i8254" frequency 1193182 Hz quality 0 
CPU: Intel(R) Pentium(R) 4 CPU 3.00GHz (2994.90-MHz 686-class CPU) 
   Origin = "GenuineIntel" Id = 0xf41 Stepping = 1 

Features=0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE 
,MCA,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE> 
   Hyperthreading: 2 logical CPUs 
real memory = 1072562176 (1022 MB) 
avail memory = 1044230144 (995 MB) 
ACPI APIC Table: <IntelR AWRDACPI> 
FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs 
cpu0 (BSP): APIC ID: 0 
cpu1 (AP): APIC ID: 1 
ioapic0: Changing APIC ID to 2 
ioapic0 <Version 2.0> irqs 0-23 on motherboard 
ioapic1 <Version 2.0> irqs 24-47 on motherboard 
npx0: <math processor> on motherboard 
npx0: INT 16 interface 
acpi0: <IntelR AWRDACPI> on motherboard 
acpi0: Power Button (fixed) 
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000 
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x408-0x40b on acpi0 
cpu0: <ACPI CPU> on acpi0 
cpu1: <ACPI CPU> on acpi0 
acpi_button0: <Power Button> on acpi0 
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0 
pci0: <ACPI PCI bus> on pcib0 
pcib1: <ACPI PCI-PCI bridge> at device 3.0 on pci0 
pci1: <ACPI PCI bus> on pcib1 
em0: <Intel(R) PRO/1000 Network Connection, Version - 1.7.35> port 
0xc000-0xc01f mem 0xf2000000-0xf201ffff irq 18 at device 1.0 on pci1 
em0: Ethernet address: 00:30:48:83:ef:8c 
em0: Speed:N/A Duplex:N/A 
pcib2: <ACPI PCI-PCI bridge> at device 28.0 on pci0 
pci2: <ACPI PCI bus> on pcib2 
uhci0: <UHCI (generic) USB controller> port 0xe100-0xe11f irq 16 at 
device 29.0 on pci0 
usb0: <UHCI (generic) USB controller> on uhci0 
usb0: USB revision 1.0 
uhub0: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1 
uhub0: 2 ports with 2 removable, self powered 
uhci1: <UHCI (generic) USB controller> port 0xe000-0xe01f irq 19 at 
device 29.1 on pci0 
usb1: <UHCI (generic) USB controller> on uhci1 
usb1: USB revision 1.0 
uhub1: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1 
uhub1: 2 ports with 2 removable, self powered 
pci0: <base peripheral> at device 29.4 (no driver attached) 
pci0: <base peripheral, interrupt controller> at device 29.5 (no 
driver attached) 
ehci0: <EHCI (generic) USB 2.0 controller> mem 0xf2100000-0xf21003ff 
irq 23 at device 29.7 on pci0 
usb2: EHCI version 1.0 
usb2: companion controllers, 2 ports each: usb0 usb1 
usb2: <EHCI (generic) USB 2.0 controller> on ehci0 
usb2: USB revision 2.0 
uhub2: Intel EHCI root hub, class 9/0, rev 2.00/1.00, addr 1 
uhub2: 4 ports with 4 removable, self powered 
pcib3: <ACPI PCI-PCI bridge> at device 30.0 on pci0 
pci3: <ACPI PCI bus> on pcib3 
pci3: <display, VGA> at device 9.0 (no driver attached) 
em1: <Intel(R) PRO/1000 Network Connection, Version - 1.7.35> port 
0xd100-0xd13f mem 0xf1000000-0xf101ffff irq 19 at device 10.0 on pci3 
em1: Ethernet address: 00:30:48:83:ef:8d 
em1: Speed:N/A Duplex:N/A 
isab0: <PCI-ISA bridge> at device 31.0 on pci0 
isa0: <ISA bus> on isab0 
atapci0: <Intel 6300ESB UDMA100 controller> port 0xf000-0xf00f, 
0x376,0x170-0x177,0x3f6,0x1f0-0x1f7 at device 31.1 on pci0 
ata0: channel #0 on atapci0 
ata1: channel #1 on atapci0 
atapci1: <Intel 6300ESB SATA150 controller> port 0xe600-0xe60f, 
0xe500-0xe503,0xe400-0xe407,0xe300-0xe303,0xe200-0xe207 irq 18 at 
device 31.2 on pci0 
ata2: channel #0 on atapci1 
ata3: channel #1 on atapci1 
pci0: <serial bus, SMBus> at device 31.3 (no driver attached) 
acpi_tz0: <Thermal Zone> on acpi0 
fdc0: <floppy drive controller> port 0x3f7,0x3f0-0x3f5 irq 6 drq 2 on 
acpi0 
sio0: <16550A-compatible COM port> port 0x3f8-0x3ff irq 4 flags 0x10 
on acpi0 
sio0: type 16550A 
sio1: <16550A-compatible COM port> port 0x2f8-0x2ff irq 3 on acpi0 
sio1: type 16550A 
ppc0: <Standard parallel printer port> port 0x778-0x77b,0x378-0x37f 
irq 7 on acpi0 
ppc0: Generic chipset (NIBBLE-only) in COMPATIBLE mode 
ppbus0: <Parallel port bus> on ppc0 
ppi0: <Parallel I/O> on ppbus0 
atkbdc0: <Keyboard controller (i8042)> port 0x64,0x60 irq 1 on acpi0 
atkbd0: <AT Keyboard> irq 1 on atkbdc0 
kbd0 at atkbd0 
pmtimer0 on isa0 
orm0: <ISA Option ROM> at iomem 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 
em0: Link is up 100 Mbps Full Duplex 
ad4: 78167MB <Maxtor 6Y080M0/YAR51HW0> [158816/16/63] at ata2-master SATA150 
ad6: 194481MB <Maxtor 6L200M0/BANC1E00> [395136/16/63] at ata3-master SATA150 
SMP: AP CPU #1 Launched! 
Mounting root from ufs:/dev/ad4s1a 
em0: Link is up 100 Mbps Full Duplex 
Accounting enabled 
pflog0: promiscuous mode enabled 
em0: Link is up 100 Mbps Full Duplex 
em0: Link is up 100 Mbps Full Duplex 

Feel free to ask for other details, or tests.
>How-To-Repeat:
no idea. Most people won't have the problem, few have it, the common denominator is still to find.
>Fix:

>Release-Note:
>Audit-Trail:
>Unformatted: