Project

General

Profile

Bug #6271

dtrace caused excessive fork time

Added by Robert Mustacchi about 4 years ago. Updated about 4 years ago.

Status:
Closed
Priority:
Normal
Category:
DTrace
Start date:
2015-09-30
Due date:
% Done:

100%

Estimated time:
Difficulty:
Hard
Tags:

Description

A customer experienced a Manatee outage today during an upgrade. There was a cascading failure upstack, but the root cause was that the postmaster process was spending between 50-90% of its
time in SYS time, and almost all of that was in fork(2):

$ prstat -mLc -p 49133 1
Please wait...
   PID USERNAME USR SYS TRP TFL DFL LCK SLP LAT VCX ICX SCL SIG PROCESS/LWPID 
 49133 postgres 0.4  79 0.0 0.0 0.0 0.0  21 0.1  11  41 173   8 postgres/1
Total: 1 processes, 1 lwps, load averages: 0.43, 0.43, 0.43
   PID USERNAME USR SYS TRP TFL DFL LCK SLP LAT VCX ICX SCL SIG PROCESS/LWPID 
 49133 postgres 0.3  66 0.0 0.0 0.0 0.0  33 0.0  16  25 134   6 postgres/1
Total: 1 processes, 1 lwps, load averages: 0.43, 0.43, 0.43
   PID USERNAME USR SYS TRP TFL DFL LCK SLP LAT VCX ICX SCL SIG PROCESS/LWPID 
 49133 postgres 0.2  44 0.0 0.0 0.0 0.0  56 0.1  15  33  75   3 postgres/1
Total: 1 processes, 1 lwps, load averages: 0.43, 0.43, 0.43
   PID USERNAME USR SYS TRP TFL DFL LCK SLP LAT VCX ICX SCL SIG PROCESS/LWPID 
 49133 postgres 0.3  49 0.0 0.0 0.0 0.0  50 0.0  15  28 113   6 postgres/1
Total: 1 processes, 1 lwps, load averages: 0.43, 0.43, 0.43
   PID USERNAME USR SYS TRP TFL DFL LCK SLP LAT VCX ICX SCL SIG PROCESS/LWPID 
 49133 postgres 0.2  55 0.0 0.0 0.0 0.0  44 0.0  13  23  80   4 postgres/1
Total: 1 processes, 1 lwps, load averages: 0.42, 0.43, 0.43
   PID USERNAME USR SYS TRP TFL DFL LCK SLP LAT VCX ICX SCL SIG PROCESS/LWPID 
 49133 postgres 0.6  98 0.0 0.0 0.0 0.0 1.5 0.1   7  47 256  13 postgres/1
Total: 1 processes, 1 lwps, load averages: 0.42, 0.43, 0.43
   PID USERNAME USR SYS TRP TFL DFL LCK SLP LAT VCX ICX SCL SIG PROCESS/LWPID 
 49133 postgres 0.5  90 0.0 0.0 0.0 0.0 9.6 0.1   7  71 217  12 postgres/1
Total: 1 processes, 1 lwps, load averages: 0.42, 0.43, 0.43
   PID USERNAME USR SYS TRP TFL DFL LCK SLP LAT VCX ICX SCL SIG PROCESS/LWPID 
 49133 postgres 0.6  98 0.0 0.0 0.0 0.0 1.1 0.1   6  62 223  11 postgres/1
...
# dtrace -n 'profile-97/pid == 49133/{ @[stack()] = count(); }' -c 'sleep 30'
dtrace: description 'profile-97' matched 1 probe
dtrace: pid 2204 has exited

              unix`mutex_vector_enter
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              genunix`kmem_cache_alloc+0x89
              genunix`kmem_zalloc+0x47
              fasttrap`fasttrap_meta_create_probe+0x166
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              dtrace`dtrace_enabling_provide+0xaa
              dtrace`dtrace_register+0x2f8
              fasttrap`fasttrap_provider_lookup+0x2f3
              fasttrap`fasttrap_meta_provide+0x93
              dtrace`dtrace_helper_provide_one+0xf2
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              dtrace`dtrace_enabling_provide+0xae
              dtrace`dtrace_register+0x2f8
              fasttrap`fasttrap_provider_lookup+0x2f3
              fasttrap`fasttrap_meta_provide+0x93
              dtrace`dtrace_helper_provide_one+0xf2
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`hat_page_setattr+0x30
              unix`hati_update_pte+0x117
              unix`hat_updateattr+0x183
              unix`hat_clrattr+0x23
              genunix`segvn_dup+0x415
              genunix`as_dup+0x11f
              genunix`cfork+0x996
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`sys_rtt_common+0x1b0
              unix`_sys_rtt_ints_disabled+0x8
              dtrace`dtrace_match_probe+0x8
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              genunix`segvn_dup+0xa4
              genunix`as_dup+0x11f
              genunix`cfork+0x996
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              genunix`syscall_mstate+0x124
              unix`sys_syscall+0x10e
                1

              unix`hwblkpagecopy+0x175
              unix`ppcopy+0x1c5
              genunix`anon_private+0x1df
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              genunix`kmem_zalloc+0xe2
              fasttrap`fasttrap_meta_create_probe+0x2af
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`mutex_delay_default
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_probe_lookup+0x7c
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`mutex_delay_default
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_register+0x2c1
              fasttrap`fasttrap_provider_lookup+0x2f3
              fasttrap`fasttrap_meta_provide+0x93
              dtrace`dtrace_helper_provide_one+0xf2
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`mutex_delay_default
              unix`lock_set_spl_spin+0xb2
              genunix`disp_lock_enter+0x26
              unix`disp_getbest+0x28
              unix`disp+0x53
              unix`swtch+0xba
              unix`preempt+0xec
              unix`kpreempt+0x98
              unix`sys_rtt_common+0x1ba
              unix`_sys_rtt_ints_disabled+0x8
              dtrace`dtrace_match_probe+0x54
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
                1

              unix`page_sub_common+0x35
              unix`page_sub+0x22
              unix`page_get_mnode_freelist+0x375
              unix`page_get_freelist+0x16d
              unix`page_create_va+0x2ad
              genunix`swap_getapage+0x113
              genunix`swap_getpage+0x90
              genunix`fop_getpage+0x7e
              genunix`anon_private+0x160
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              unix`mutex_delay_default+0x7
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_helper_provider_register+0x45
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`mutex_delay_default+0x7
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_enabling_provide+0x166
              dtrace`dtrace_register+0x2f8
              fasttrap`fasttrap_provider_lookup+0x2f3
              fasttrap`fasttrap_meta_provide+0x93
              dtrace`dtrace_helper_provide_one+0xf2
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`mutex_delay_default+0x7
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_register+0x2c1
              fasttrap`fasttrap_provider_lookup+0x2f3
              fasttrap`fasttrap_meta_provide+0x93
              dtrace`dtrace_helper_provide_one+0xf2
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              genunix`new_cpu_mstate+0x29
              genunix`new_mstate+0x184
              unix`trap+0x174
              unix`0xfffffffffb8001d6
                1

              unix`page_numtopp_nolock+0x5a
              unix`hat_updateattr+0xef
              unix`hat_clrattr+0x23
              genunix`segvn_dup+0x415
              genunix`as_dup+0x11f
              genunix`cfork+0x996
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`mutex_delay_default+0xc
              unix`mutex_vector_enter+0xc5
              genunix`mod_hold_stub+0x2b
              unix`stubs_common_code+0x1f
              genunix`forklwp+0x1e4
              genunix`cfork+0x690
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`mutex_delay_default+0xc
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_helper_provider_register+0x39
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              genunix`anon_dup+0x132
              genunix`segvn_dup+0x52b
              genunix`as_dup+0x11f
              genunix`cfork+0x996
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`mutex_owner_running+0x3
              dtrace`dtrace_probe_create+0x61
              fasttrap`fasttrap_meta_create_probe+0x2af
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`page_sub_common+0x44
              unix`page_sub+0x22
              unix`page_get_mnode_freelist+0x375
              unix`page_get_freelist+0x16d
              unix`page_create_va+0x2ad
              genunix`swap_getapage+0x113
              genunix`swap_getpage+0x90
              genunix`fop_getpage+0x7e
              genunix`anon_private+0x160
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              unix`htable_lookup+0xc6
              unix`htable_walk+0x17e
              unix`hat_updateattr+0x99
              unix`hat_clrattr+0x23
              genunix`segvn_dup+0x415
              genunix`as_dup+0x11f
              genunix`cfork+0x996
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`hwblkpagecopy+0xa6
              unix`ppcopy+0x1c5
              genunix`anon_private+0x1df
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              dtrace`dtrace_probe_lookup+0x3b
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              genunix`cpu_update_pct+0x80
              genunix`new_mstate+0x73
              unix`trap+0x63e
              unix`0xfffffffffb8001d6
                1

              unix`page_lookup_create+0x168
              unix`page_lookup+0x21
              genunix`swap_getapage+0xea
              genunix`swap_getpage+0x90
              genunix`fop_getpage+0x7e
              genunix`anon_private+0x160
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              unix`mutex_owner_running+0x18
              dtrace`dtrace_probe_create+0x61
              fasttrap`fasttrap_meta_create_probe+0x2af
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`mutex_owner_running+0x18
              dtrace`dtrace_helpers_duplicate+0x37
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`mutex_enter+0x10
              genunix`rctl_gp_alloc+0x70
              genunix`rctl_set_dup_prealloc+0x49
              genunix`cfork+0x200
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`mutex_enter+0x10
              unix`hat_pte_unmap+0xbc
              unix`hat_unload_callback+0x259
              unix`hat_unload+0x3e
              genunix`anon_private+0x214
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              unix`mutex_enter+0x10
              unix`hat_pte_unmap+0xbc
              unix`hat_unload_callback+0x259
              unix`hat_unload+0x3e
              genunix`anon_private+0x214
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0xd23
              unix`0xfffffffffb8001d6
              unix`0xfffffffffb8540da
              genunix`psig+0x440
              genunix`post_syscall+0x82d
              unix`0xfffffffffb800caa
                1

              unix`mutex_enter+0x10
              fasttrap`fasttrap_meta_create_probe+0x2af
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`mutex_enter+0x10
              unix`hat_unload_callback+0x262
              unix`hat_unload+0x3e
              genunix`anon_private+0x214
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              unix`mutex_enter+0x10
              genunix`kmem_zalloc+0x47
              genunix`anon_create+0x81
              genunix`anonmap_alloc+0x61
              genunix`segvn_dup+0x1bb
              genunix`as_dup+0x11f
              genunix`cfork+0x996
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`mutex_enter+0x10
              genunix`kmem_zalloc+0x47
              fasttrap`fasttrap_meta_create_probe+0x166
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`mutex_enter+0x10
              unix`page_get_mnode_freelist+0x32c
              unix`page_get_freelist+0x16d
              unix`page_create_va+0x2ad
              genunix`swap_getapage+0x113
              genunix`swap_getpage+0x90
              genunix`fop_getpage+0x7e
              genunix`anon_private+0x160
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              unix`mutex_enter+0x10
              genunix`segvn_dup+0x52b
              genunix`as_dup+0x11f
              genunix`cfork+0x996
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`lgrp_stat_add+0x4c
              unix`lgrp_mem_choose+0x439
              unix`page_create_va+0x283
              genunix`swap_getapage+0x113
              genunix`swap_getpage+0x90
              genunix`fop_getpage+0x7e
              genunix`anon_private+0x160
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              genunix`rctl_set_tearoff+0x78
              genunix`task_detach+0x61
              genunix`freeproc+0x12d
              genunix`waitid+0x47b
              genunix`waitsys+0x2f
              unix`sys_syscall+0x17a
                1

              dtrace`dtrace_match_probe+0xc0
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`page_vpadd+0x23
              unix`page_do_hashin+0xfd
              unix`page_hashin+0x59
              unix`page_create_va+0x389
              genunix`swap_getapage+0x113
              genunix`swap_getpage+0x90
              genunix`fop_getpage+0x7e
              genunix`anon_private+0x160
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              unix`tsc_read+0x3
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_probe_create+0x61
              fasttrap`fasttrap_meta_create_probe+0x2af
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`tsc_read+0x3
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_helpers_duplicate+0x37
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`page_trylock+0x63
              unix`page_trylock_cons+0x27
              unix`page_get_mnode_freelist+0x185
              unix`page_get_freelist+0x16d
              unix`page_create_va+0x2ad
              genunix`swap_getapage+0x113
              genunix`swap_getpage+0x90
              genunix`fop_getpage+0x7e
              genunix`anon_private+0x160
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              genunix`vmem_hash_insert+0x59
              genunix`vmem_seg_alloc+0x12d
              genunix`vmem_xalloc+0x28a
              genunix`vmem_alloc+0x137
              dtrace`dtrace_probe_create+0x77
              fasttrap`fasttrap_meta_create_probe+0x2af
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              genunix`new_mstate+0xdc
              unix`trap+0x63e
              unix`0xfffffffffb8001d6
                1

              genunix`segvn_dup+0x520
              genunix`as_dup+0x11f
              genunix`cfork+0x996
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`lgrp_mem_choose+0x92
              unix`page_create_va+0x283
              genunix`swap_getapage+0x113
              genunix`swap_getpage+0x90
              genunix`fop_getpage+0x7e
              genunix`anon_private+0x160
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              dtrace`dtrace_hash_collisions+0x63
              dtrace`dtrace_match+0x267
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`page_vpadd+0x36
              unix`page_do_hashin+0xfd
              unix`page_hashin+0x59
              unix`page_create_va+0x389
              genunix`swap_getapage+0x113
              genunix`swap_getpage+0x90
              genunix`fop_getpage+0x7e
              genunix`anon_private+0x160
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              dtrace`dtrace_hash_str+0x2c
              dtrace`dtrace_hash_lookup+0x33
              dtrace`dtrace_match+0xd0
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              dtrace`dtrace_hash_add+0x3e
              dtrace`dtrace_probe_create+0x10f
              fasttrap`fasttrap_meta_create_probe+0x2af
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              genunix`segvn_dup+0x40
              genunix`as_dup+0x11f
              genunix`cfork+0x996
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              genunix`anon_dup+0xaa
              genunix`segvn_dup+0x52b
              genunix`as_dup+0x11f
              genunix`cfork+0x996
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              dtrace`dtrace_hash_str+0x3f
              dtrace`dtrace_match+0x28b
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`htable_lookup+0x44
              unix`hati_load_common+0x74
              unix`hat_memload+0x75
              genunix`segvn_faultpage+0x3bf
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              unix`mutex_vector_enter+0xc5
              genunix`mod_hold_stub+0x2b
              unix`stubs_common_code+0x1f
              genunix`cfork+0x9d3
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              genunix`anon_get_next_ptr+0xbd
              genunix`anon_dup+0x160
              genunix`segvn_dup+0x52b
              genunix`as_dup+0x11f
              genunix`cfork+0x996
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`page_ctr_sub_internal+0xe1
              unix`page_ctr_sub+0x76
              unix`page_get_mnode_freelist+0x32c
              unix`page_get_freelist+0x16d
              unix`page_create_va+0x2ad
              genunix`swap_getapage+0x113
              genunix`swap_getpage+0x90
              genunix`fop_getpage+0x7e
              genunix`anon_private+0x160
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              unix`strcmp+0x21
              dtrace`dtrace_hash_collisions+0x68
              dtrace`dtrace_match+0x267
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`strcmp+0x21
              dtrace`dtrace_hash_collisions+0x68
              dtrace`dtrace_match+0x28b
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`strcmp+0x21
              dtrace`dtrace_hash_add+0x78
              dtrace`dtrace_probe_create+0xf1
              fasttrap`fasttrap_meta_create_probe+0x2af
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`page_lookup_create+0xe3
              unix`page_lookup+0x21
              genunix`swap_getapage+0xea
              genunix`swap_getpage+0x90
              genunix`fop_getpage+0x7e
              genunix`anon_private+0x160
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              unix`bzero+0x3a7
              genunix`anon_create+0x81
              genunix`anonmap_alloc+0x61
              genunix`segvn_dup+0x1bb
              genunix`as_dup+0x11f
              genunix`cfork+0x996
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`htable_walk+0xc7
              unix`hat_updateattr+0x99
              unix`hat_clrattr+0x23
              genunix`segvn_dup+0x415
              genunix`as_dup+0x11f
              genunix`cfork+0x996
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`strcmp+0x29
              dtrace`dtrace_hash_add+0x78
              dtrace`dtrace_probe_create+0x10f
              fasttrap`fasttrap_meta_create_probe+0x2af
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              dtrace`dtrace_hash_add+0x6c
              dtrace`dtrace_probe_create+0x10f
              fasttrap`fasttrap_meta_create_probe+0x2af
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`mutex_owner+0xd
              genunix`vmem_is_populator+0x2a
              unix`hment_free+0x45
              unix`hat_pte_unmap+0x161
              unix`hat_unload_callback+0x259
              unix`hat_unload+0x3e
              genunix`anon_private+0x214
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              unix`default_lock_delay+0x3f
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_probe_lookup+0x7c
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`page_lookup_create+0xf0
              unix`page_lookup+0x21
              genunix`swap_getapage+0xea
              genunix`swap_getpage+0x90
              genunix`fop_getpage+0x7e
              genunix`anon_private+0x160
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              genunix`as_segcompar+0x1
              genunix`as_addseg+0xb5
              genunix`seg_attach+0x2b
              genunix`seg_alloc+0xc8
              genunix`as_dup+0x103
              genunix`cfork+0x996
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`membar_enter+0x3
              FSS`fss_wakeup+0x96
              genunix`turnstile_wakeup+0xbe
              unix`mutex_vector_exit+0x68
              dtrace`dtrace_probe_lookup+0xa7
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              genunix`fcnt_add+0x48
              genunix`getproc+0x63b
              genunix`cfork+0x17f
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              genunix`swapfs_getvp+0x1e
              genunix`anon_alloc+0x142
              genunix`anon_private+0x106
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              unix`default_lock_delay+0x4e
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_probe_create+0x61
              fasttrap`fasttrap_meta_create_probe+0x2af
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`default_lock_delay+0x4e
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_helpers_duplicate+0x37
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`default_lock_delay+0x4e
              unix`mutex_vector_enter+0xc5
              genunix`mod_hold_stub+0x2b
              unix`stubs_common_code+0x1f
              genunix`cfork+0x9d3
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`cmt_ev_thread_swtch
              unix`swtch+0xe4
              genunix`turnstile_block+0x262
              unix`mutex_vector_enter+0x3a3
              genunix`mod_hold_stub+0x2b
              unix`stubs_common_code+0x1f
              genunix`cfork+0x9d3
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`default_lock_delay+0x50
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_probe_create+0x61
              fasttrap`fasttrap_meta_create_probe+0x2af
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`default_lock_delay+0x54
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_probe_create+0x61
              fasttrap`fasttrap_meta_create_probe+0x2af
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`x86pte_update+0x48
              unix`hati_update_pte+0x51
              unix`hat_updateattr+0x183
              unix`hat_clrattr+0x23
              genunix`segvn_dup+0x415
              genunix`as_dup+0x11f
              genunix`cfork+0x996
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`mutex_vector_enter+0xfb
              dtrace`dtrace_probe_create+0x61
              fasttrap`fasttrap_meta_create_probe+0x2af
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`mutex_vector_enter+0xfb
              dtrace`dtrace_probe_lookup+0x7c
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`mutex_vector_enter+0xfb
              dtrace`dtrace_helper_provider_register+0x39
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                1

              unix`mtype_func+0x9f
              unix`page_get_mnode_freelist+0x4f
              unix`page_get_freelist+0x16d
              unix`page_create_va+0x2ad
              genunix`swap_getapage+0x113
              genunix`swap_getpage+0x90
              genunix`fop_getpage+0x7e
              genunix`anon_private+0x160
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                1

              dtrace`dtrace_match_string+0x20
              dtrace`dtrace_match_probe+0x78
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                2

              dtrace`dtrace_match_string+0x25
              dtrace`dtrace_match_probe+0x78
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                2

              dtrace`dtrace_match_probe+0x6c
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                2

              unix`mutex_delay_default
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_helper_provider_register+0x39
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                2

              unix`mutex_delay_default+0x7
              unix`lock_set_spl_spin+0xb2
              genunix`disp_lock_enter+0x26
              unix`disp_getbest+0x28
              unix`disp+0x53
              unix`swtch+0xba
              unix`preempt+0xec
              unix`kpreempt+0x98
              unix`sys_rtt_common+0x1ba
              unix`_sys_rtt_ints_disabled+0x8
              dtrace`dtrace_match_probe+0x40
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
                2

              unix`mutex_delay_default+0xc
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_helpers_duplicate+0x37
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                2

              unix`tsc_read+0x3
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_probe_lookup+0x7c
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                2

              unix`tsc_read+0x3
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_helper_provider_register+0x39
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                2

              unix`bzero+0x3a7
              genunix`as_alloc+0xb1
              genunix`as_dup+0x4d
              genunix`cfork+0x996
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                2

              unix`default_lock_delay+0x3f
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_probe_create+0x61
              fasttrap`fasttrap_meta_create_probe+0x2af
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                2

              unix`default_lock_delay+0x3f
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_helpers_duplicate+0x37
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                2

              unix`default_lock_delay+0x50
              unix`mutex_vector_enter+0xc5
              genunix`mod_hold_stub+0x2b
              unix`stubs_common_code+0x1f
              genunix`cfork+0x9d3
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                2

              unix`default_lock_delay+0x50
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_helper_provider_register+0x39
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                2

              unix`page_numtopp_nolock+0x130
              unix`hat_updateattr+0xef
              unix`hat_clrattr+0x23
              genunix`segvn_dup+0x415
              genunix`as_dup+0x11f
              genunix`cfork+0x996
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                3

              dtrace`dtrace_match_probe+0x54
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                3

              unix`mutex_delay_default+0x7
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_helpers_duplicate+0x37
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                3

              unix`mutex_delay_default+0x7
              unix`mutex_vector_enter+0xc5
              genunix`mod_hold_stub+0x2b
              unix`stubs_common_code+0x1f
              genunix`cfork+0x9d3
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                3

              unix`mutex_enter+0x10
              genunix`anon_private+0x106
              genunix`segvn_faultpage+0x325
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                3

              unix`tsc_read+0x3
              unix`mutex_vector_enter+0xc5
              genunix`mod_hold_stub+0x2b
              unix`stubs_common_code+0x1f
              genunix`cfork+0x9d3
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                3

              unix`strcmp+0x1b
              dtrace`dtrace_match_string+0x20
              dtrace`dtrace_match_probe+0x78
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                3

              unix`default_lock_delay+0x3f
              unix`mutex_vector_enter+0xc5
              genunix`mod_hold_stub+0x2b
              unix`stubs_common_code+0x1f
              genunix`cfork+0x9d3
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                3

              unix`default_lock_delay+0x3f
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_helper_provider_register+0x39
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                3

              unix`strcmp+0x3e
              dtrace`dtrace_match_string+0x20
              dtrace`dtrace_match_probe+0x78
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                3

              unix`default_lock_delay+0x4e
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_helper_provider_register+0x39
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                3

              dtrace`dtrace_match_string+0x29
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                4

              unix`mutex_delay_default
              unix`mutex_vector_enter+0xc5
              genunix`mod_hold_stub+0x2b
              unix`stubs_common_code+0x1f
              genunix`cfork+0x9d3
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                4

              genunix`anon_getpage+0x46
              genunix`segvn_faultpage+0x168
              genunix`segvn_fault+0x8e6
              genunix`as_fault+0x37a
              unix`pagefault+0x96
              unix`trap+0x2c7
              unix`0xfffffffffb8001d6
                4

              unix`strcmp+0x21
              dtrace`dtrace_match_string+0x20
              dtrace`dtrace_match_probe+0x8d
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                4

              unix`strcmp+0x21
              dtrace`dtrace_match_string+0x20
              dtrace`dtrace_match_probe+0xa2
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                4

              unix`strcmp+0x43
              dtrace`dtrace_match_probe+0x78
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                4

              dtrace`dtrace_match_probe+0x64
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                5

              dtrace`dtrace_match_probe+0x4d
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                6

              dtrace`dtrace_match_probe+0x65
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                6

              dtrace`dtrace_match_probe+0x68
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                7

              unix`mutex_delay_default+0x7
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_probe_lookup+0x7c
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                8

              dtrace`dtrace_match_string+0x19
              dtrace`dtrace_match_probe+0x78
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
                8

              unix`strcmp+0x1
              dtrace`dtrace_match_probe+0x78
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               10

              dtrace`dtrace_match_probe+0x1b
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               10

              unix`strcmp+0x42
              dtrace`dtrace_match_string+0x20
              dtrace`dtrace_match_probe+0x78
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               10

              dtrace`dtrace_match_probe+0x38
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               10

              dtrace`dtrace_match_string+0x28
              dtrace`dtrace_match_probe+0x78
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               11

              dtrace`dtrace_match+0x119
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               11

              unix`strcmp+0xc
              dtrace`dtrace_match_string+0x20
              dtrace`dtrace_match_probe+0x78
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               12

              dtrace`dtrace_match_probe+0xc
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               12

              unix`mutex_delay_default+0x7
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_probe_create+0x61
              fasttrap`fasttrap_meta_create_probe+0x2af
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               13

              dtrace`dtrace_match_probe+0x78
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               13

              dtrace`dtrace_match+0xe0
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               13

              dtrace`dtrace_match_probe+0x1
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               13

               14

              dtrace`dtrace_match_probe+0x75
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               14

              dtrace`dtrace_match_string+0x1
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               14

              dtrace`dtrace_match_probe+0x5c
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               15

              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               15

              unix`strcmp+0x45
              dtrace`dtrace_match_probe+0x78
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               15

              dtrace`dtrace_match+0x11d
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               18

              dtrace`dtrace_match_probe+0x29
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               18

              dtrace`dtrace_match_string+0xa
              dtrace`dtrace_match_probe+0x78
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               18

              dtrace`dtrace_match+0xf2
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               19

              unix`strcmp+0x29
              dtrace`dtrace_match_string+0x20
              dtrace`dtrace_match_probe+0x78
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               25

              unix`mutex_delay_default+0x7
              unix`mutex_vector_enter+0xc5
              dtrace`dtrace_helper_provider_register+0x39
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               27

              unix`strcmp+0x1e
              dtrace`dtrace_match_string+0x20
              dtrace`dtrace_match_probe+0x78
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               48

              unix`strcmp+0x21
              dtrace`dtrace_match_string+0x20
              dtrace`dtrace_match_probe+0x78
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               52

              unix`strcmp+0x18
              dtrace`dtrace_match_string+0x20
              dtrace`dtrace_match_probe+0x78
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               82

              unix`strcmp+0x25
              dtrace`dtrace_match_string+0x20
              dtrace`dtrace_match_probe+0x78
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               86

              dtrace`dtrace_match_probe+0x48
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
               95

              dtrace`dtrace_match+0x121
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
              483

              dtrace`dtrace_match_probe+0x40
              dtrace`dtrace_match+0xfa
              dtrace`dtrace_probe_lookup+0x99
              fasttrap`fasttrap_meta_create_probe+0x120
              dtrace`dtrace_helper_provide_one+0x1ab
              dtrace`dtrace_helper_provide+0x6f
              dtrace`dtrace_helper_provider_register+0x163
              dtrace`dtrace_helpers_duplicate+0x1df
              genunix`cfork+0x9ea
              genunix`forksys+0x3c
              unix`sys_syscall+0x17a
              680

Here's the distribution of fork times for about 30 seconds:

$ dtrace -n 'syscall::fork*:entry{ self->f = timestamp; }' -n 'syscall::fork*:return/self->f/{ @[pid] = quantize(timestamp - self->f); self->f = 0; }'  -c 'sleep 30'
dtrace: description 'syscall::fork*:entry' matched 1 probe
dtrace: description 'syscall::fork*:return' matched 1 probe
dtrace: pid 5723 has exited

...
    49133
           value  ------------- Distribution ------------- count    
        16777216 |                                         0        
        33554432 |@                                        9        
        67108864 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@          212      
       134217728 |@@@@@@                                   40       
       268435456 |@@                                       12       
       536870912 |                                         1        
      1073741824 |                                         0        

It looks like the fasttrap provider is checking that the probe doesn't already exist. That lookup may end up scanning a hash by module, function, or probe name. All of those sets are large on this system.

Module:

# dtrace -l -n 'postgresql*:::' | awk '{print $3}' | sort | uniq -c | sort -n | tail
   1 MODULE
16776 postgres

Function:

# dtrace -l -n 'postgresql*:::' | awk '{print $4}' | sort | uniq -c | sort -n | tail
 466 PortalRunMulti
 466 PostgresMain
 466 ShutdownCLOG
 466 ShutdownMultiXact
 466 ShutdownSUBTRANS
 466 XLogInsert
 699 LWLockAcquire
 932 LWLockAcquireOrWait
 932 ReadBuffer_common
1398 CheckPointBuffers

Probe name:

# dtrace -l -n 'postgresql*:::' | awk '{print $5}' | sort | uniq -c | sort -n | tail
 466 lwlock-wait-start
 466 multixact-checkpoint-done
 466 multixact-checkpoint-start
 466 query-execute-done
 466 query-execute-start
 466 query-rewrite-done
 466 query-rewrite-start
 466 subtrans-checkpoint-done
 466 subtrans-checkpoint-start
 932 sort-start

and there are 72 probes to add, so we do this 72 times.

In running a test that creates 500 processes with 100 USDT probes each (each with different function and name), the time to create 1000 processes was found to be ~11.8 ms per fork. Eliminating the lookup eliminated more than 80% of this time, taking it to about 2.2 ms per fork. However, eliminating the helper provider forking entirely eliminated 90% off that, taking it to just 0.3 ms per fork.

Looking more closely at these results with DTrace reveals that much of the 2.2 ms is spent contending on a lock held by the asynchronous cleanup of the provider from the (previous) exiting process. This does not correspond with what we would see in the wild under this condition; modifying the test program to focus on fork time and allowing for settling time after the exit shows a different story: with the helper duplication in place but with the lookup eliminated, the time was ~390 usecs. With the helper duplication eliminated, the time dropped to ~265 usecs. While this is a savings to be sure, it is nothing like the order-of-magnitude difference when contention with provider cleanup is in play.

History

#1

Updated by Electric Monk about 4 years ago

  • Status changed from New to Closed

git commit 7bd3c1d12d0c764e1517c3aca62c634409356764

commit  7bd3c1d12d0c764e1517c3aca62c634409356764
Author: Bryan Cantrill <bryan@joyent.com>
Date:   2015-10-06T21:53:29.000Z

    6271 dtrace caused excessive fork time
    Reviewed by: Adam Leventhal <ahl@delphix.com>
    Reviewed by: Dan McDonald <danmcd@omniti.com>
    Reviewed by: Richard Lowe <richlowe@richlowe.net>
    Approved by: Gordon Ross <gwr@nexenta.com>

Also available in: Atom PDF