Testing notes:

I ran the old and new versions of pfiles on all system processes and compared the results. The only differences in output were around locking where the new version provides information that was missing from the old, for example:

--- old 2020-01-19 03:20:31.284442178 +0000
+++ new 2020-01-19 03:20:31.265771950 +0000
@@ -14,6 +14,7 @@
       offset:0
    3: S_IFREG mode:0644 dev:266,65538 ino:2433 uid:0 gid:0 size:59510
       O_RDWR|O_APPEND|O_CREAT
+      advisory write lock set by process 100421
       /var/saf/_log
       offset:59510
    4: S_IFIFO mode:0600 dev:266,65538 ino:2434 uid:0 gid:0 size:0

Locking¶

I also did specific testing around locking, using a test program that creates four locks, read-only and read-write, and POSIX and OFD:

bloody# ./locks
    Locked (RO): 3
OFD Locked (RO): 4
    Locked (RW): 5
OFD Locked (RW): 6
^Z
zsh: suspended  ./locks
bloody# bg
[1]  + continued  ./locks
bloody# pfiles $!
101071: ./locks
  Current rlimit: 65536 file descriptors
   0: S_IFCHR mode:0620 dev:554,0 ino:3857478227 uid:100 gid:7 rdev:172,2
      O_RDWR|O_NOCTTY|O_LARGEFILE
      /dev/pts/2
      offset:297341
   1: S_IFCHR mode:0620 dev:554,0 ino:3857478227 uid:100 gid:7 rdev:172,2
      O_RDWR|O_NOCTTY|O_LARGEFILE
      /dev/pts/2
      offset:297341
   2: S_IFCHR mode:0620 dev:554,0 ino:3857478227 uid:100 gid:7 rdev:172,2
      O_RDWR|O_NOCTTY|O_LARGEFILE
      /dev/pts/2
      offset:297341
   3: S_IFREG mode:0600 dev:559,2 ino:3950032994 uid:100 gid:1 size:4
      O_RDWR|O_CREAT|O_TRUNC
      advisory read lock set by process 101071
      /tmp/locked
      offset:4
   4: S_IFREG mode:0600 dev:559,2 ino:3950032901 uid:100 gid:1 size:4
      O_RDWR|O_CREAT|O_TRUNC
      advisory read lock set
      /tmp/locked.ofd
      offset:4
   5: S_IFREG mode:0600 dev:559,2 ino:3952979415 uid:100 gid:1 size:4
      O_RDWR|O_CREAT|O_TRUNC
      advisory write lock set by process 100605
      /tmp/locked.rw
      offset:4
   6: S_IFREG mode:0600 dev:559,2 ino:3952979384 uid:100 gid:1 size:4
      O_RDWR|O_CREAT|O_TRUNC
      advisory write lock set
      /tmp/locked.rw.ofd
      offset:4

The differences between the old and new pfiles for this look as follows:

--- old 2020-01-19 03:27:51.277965769 +0000
+++ new 2020-01-19 03:27:51.261579980 +0000
@@ -14,19 +14,21 @@
       offset:310674
    3: S_IFREG mode:0600 dev:559,2 ino:3950032994 uid:100 gid:1 size:4
       O_RDWR|O_CREAT|O_TRUNC
+      advisory read lock set by process 101283
       /tmp/locked
       offset:4
    4: S_IFREG mode:0600 dev:559,2 ino:3950032901 uid:100 gid:1 size:4
       O_RDWR|O_CREAT|O_TRUNC
-      advisory read lock set by process -1
+      advisory read lock set
       /tmp/locked.ofd
       offset:4
    5: S_IFREG mode:0600 dev:559,2 ino:3952979415 uid:100 gid:1 size:4
       O_RDWR|O_CREAT|O_TRUNC
+      advisory write lock set by process 101283
       /tmp/locked.rw
       offset:4
    6: S_IFREG mode:0600 dev:559,2 ino:3952979384 uid:100 gid:1 size:4
       O_RDWR|O_CREAT|O_TRUNC
-      advisory write lock set by process -1
+      advisory write lock set
       /tmp/locked.rw.ofd
       offset:4

The old version doesn't output the information for the POSIX locks at all, and adds "by process -1" for the OFD locks.

filters¶

I created a test program that pushed a couple of socket filters onto a socket. The output was identical between the old and new pfiles:

   3: S_IFSOCK mode:0666 dev:563,0 ino:4852 uid:0 gid:0 rdev:0,0
      O_RDWR
        SOCK_STREAM
        SO_REUSEADDR,SO_SNDBUF(49152),SO_RCVBUF(128000)
        filters: dataf(prog),httpf(prog)
        sockname: AF_INET 0.0.0.0  port: 8080

door¶

I created a simple door server - output was identical between old and new versions of pfiles

   3: S_IFDOOR mode:0777 dev:556,0 ino:0 uid:0 gid:0 rdev:556,0
      O_RDWR FD_CLOEXEC  door to server[100606]

performance¶

I used Dave Eddy's test script from issue 5397 to create 1000 sockets. The new pfiles is significantly faster reporting on these than the old, and the output is identical:

bloody# ./sockets &
[2] 101522
opened 1000 sockets

bloody# time ./pfiles $! >/dev/null
./pfiles $! > /dev/null  0.61s user 3.71s system 69% cpu 6.257 total

bloody# time pfiles $! >/dev/null
pfiles $! > /dev/null  0.06s user 0.31s system 73% cpu 0.508 total

bloody# LD_PRELOAD=/usr/lib/amd64/libumem.so UMEM_DEBUG=default
/usr/bin/amd64/mdb /usr/bin/amd64/pfiles
> ::bp exit
> ::run /proc/0 /proc/1 /proc/100003 /proc/100005 /proc/100037 /proc/100042
/proc/100044 /proc/100143 /proc/100159 /proc/100169 /proc/100199 /proc/100226
/proc/100230 /proc/100261 /proc/100291 /proc/100308 /proc/100328 /proc/100344
/proc/100350 /proc/100352 /proc/100356 /proc/100360 /proc/100363 /proc/100385
/proc/100416 /proc/100417 /proc/100437 /proc/100439 /proc/100449 /proc/100461
/proc/100464 /proc/100478 /proc/100480 /proc/100512 /proc/100523 /proc/100524
/proc/100528 /proc/100622 /proc/100624 /proc/100625 /proc/100894 /proc/101239
/proc/101253 /proc/101254 /proc/2 /proc/3 /proc/4 /proc/5
0:  sched
  [system process]
... elided ...
mdb: stop at exit
mdb: target stopped at:
libc.so.1`exit: pushq  %rbp
mdb: You've got symbols!
Loading modules: [ ld.so.1 libumem.so.1 libc.so.1 libproc.so.1 ]
> ::findleaks
findleaks: no memory leaks detected
> ::umem_status
Status:         ready and active
Concurrency:    32
Logs:           (inactive)
Message buffer:

bloody# mdb unix.5 vmcore.5
Loading modules: [ unix genunix specfs dtrace mac cpu.generic uppc pcplusmp
scsi_vhci zfs ip hook neti sockfs arp usba stmf stmf_sbd mm lofs cpc crypto ufs
logindmux ptm nfs ]
> ::findleaks
CACHE             LEAKED           BUFCTL CALLER
ffffff06e1038648       1 ffffff0708721018 pci_get_irq_routing_table+0x27
------------------------------------------------------------------------
           Total       1 buffer, 512 bytes

(I opened 12246 for that leak)