1# -*- tab-width: 4 -*- ;; Emacs 2# vi: set filetype=sh tabstop=8 shiftwidth=8 noexpandtab :: Vi/ViM 3############################################################ IDENT(1) 4# 5# $Title: dwatch(8) module for slow syscall detection $ 6# $Copyright: 2026 Devin Teske. All rights reserved. $ 7# 8############################################################ DESCRIPTION 9# 10# Print syscalls whose entry-to-return latency meets or exceeds a threshold 11# (default 100 ms; tunable via DWATCH_SLOW_MS in the environment). Answers 12# "why is my application stalling?" by naming the slow operation, the time 13# it took, and any errno it returned. The default profile watches a curated 14# set of filesystem-related syscalls that are expected to be fast. Use 15# slow-syscall to watch every syscall (NB: intentionally-blocking syscalls 16# such as select(2), poll(2), kevent(2), and wait4(2) will dominate), or 17# slow-NAME (e.g., slow-connect) to watch a single syscall by name. 18# 19############################################################ PROBE 20 21case "$PROFILE" in 22slow) 23 : ${PROBE:=$( echo \ 24 syscall::open:return, \ 25 syscall::openat:return, \ 26 syscall::close:return, \ 27 syscall::read:return, \ 28 syscall::readv:return, \ 29 syscall::pread:return, \ 30 syscall::preadv:return, \ 31 syscall::write:return, \ 32 syscall::writev:return, \ 33 syscall::pwrite:return, \ 34 syscall::pwritev:return, \ 35 syscall::copy_file_range:return, \ 36 syscall::getdirentries:return, \ 37 syscall::readlink:return, \ 38 syscall::readlinkat:return, \ 39 syscall::fsync:return, \ 40 syscall::fdatasync:return, \ 41 syscall::rename:return, \ 42 syscall::renameat:return, \ 43 syscall::renameat2:return, \ 44 syscall::unlink:return, \ 45 syscall::unlinkat:return )} ;; 46slow-open) 47 : ${PROBE:=syscall::open:return, syscall::openat:return} ;; 48slow-read) 49 : ${PROBE:=$( echo \ 50 syscall::read:return, \ 51 syscall::readv:return, \ 52 syscall::pread:return, \ 53 syscall::preadv:return, \ 54 syscall::getdirentries:return, \ 55 syscall::readlink:return, \ 56 syscall::readlinkat:return )} ;; 57slow-write) 58 : ${PROBE:=$( echo \ 59 syscall::write:return, \ 60 syscall::writev:return, \ 61 syscall::pwrite:return, \ 62 syscall::pwritev:return, \ 63 syscall::copy_file_range:return )} ;; 64slow-fsync) 65 : ${PROBE:=syscall::fsync:return, syscall::fdatasync:return} ;; 66slow-syscall) 67 : ${PROBE:=syscall:::return} ;; 68*) 69 : ${PROBE:=syscall::${PROFILE#slow-}:return} 70esac 71 72# 73# Derive the matching entry probes from the return probes being watched 74# 75ENTRY_PROBE=$( echo "$PROBE" | awk 'gsub(/:return/, ":entry") || 1' ) 76 77############################################################ EVENT ACTION 78 79: ${DWATCH_SLOW_MS:=100} 80 81case "$DWATCH_SLOW_MS" in 82""|*[!0-9]*) die "DWATCH_SLOW_MS must be a number" ;; # NOTREACHED 83esac 84 85[ "$CUSTOM_TEST" ] || 86 EVENT_TEST="this->slow_ns >= (int64_t)$DWATCH_SLOW_MS * 1000000" 87 88############################################################ ACTIONS 89 90exec 9<<EOF 91self int64_t slow_ts; 92this int64_t slow_ns; 93 94$ENTRY_PROBE /* probe ID $ID */ 95{${TRACE:+ 96 printf("<$ID>");} 97 self->slow_ts = timestamp; 98} 99 100$PROBE /* probe ID $(( $ID + 1 )) */ 101{${TRACE:+ 102 printf("<$(( $ID + 1 ))>"); 103} 104 /* NB: -1 if we did not see the entry (enabled mid-syscall) */ 105 this->slow_ns = self->slow_ts ? timestamp - self->slow_ts : -1; 106 self->slow_ts = 0; 107} 108EOF 109ACTIONS=$( cat <&9 ) 110ID=$(( $ID + 2 )) 111 112############################################################ EVENT DETAILS 113 114if [ ! "$CUSTOM_DETAILS" ]; then 115exec 9<<EOF 116 /* 117 * Print syscall latency details 118 */ 119 printf("%s(2) %d.%03d ms%s%s", 120 probefunc, 121 this->slow_ns / 1000000, 122 (this->slow_ns % 1000000) / 1000, 123 errno > 0 ? " -- " : "", 124 errno > 0 ? strerror[errno] : ""); 125EOF 126EVENT_DETAILS=$( cat <&9 ) 127fi 128 129################################################################################ 130# END 131################################################################################ 132