Understand problematic processes

This is part of the Semicolon&Sons Code Diary - consisting of lessons learned on the job. You're in the unix category.

Last Updated: 2022-05-26

My CPU was heating up after enabling notifications with the jest test runner:

$ jest --watch --notify

Here's the output of

$ top -o cpu

Processes: 424 total, 4 running, 420 sleeping, 2344 threads                                                                                                                                                                                                            15:57:24

PID    COMMAND      %CPU  TIME     #TH   #WQ  #PORT MEM    PURG   CMPRS  PGRP  PPID  STATE    BOOSTS            %CPU_ME %CPU_OTHRS UID  FAULTS    COW     MSGSENT    MSGRECV    SYSBSD     SYSMACH    CSW         PAGEINS IDLEW     POWER INSTRS     CYCLES
42769  usernoted    39.3  02:02.94 3     2    145   30M    736K   0B     42769 1     running *0[1]             0.00000 39.32841   501  807098+   287     32868+     8236+      38675+     25356+     152895+     169     6         39.3  1714623073 1354092578
42871  terminal-not 28.2  01:21.19 7/1   5/1  175   10M+   0B     0B     42052 42054 running  *6[2]             7.84940 19.16940   501  409276+   274     5318+      4378+      265903+    26770+     87984+      13      731+      28.3  1600982881 1031715039
42891  terminal-not 19.6  00:53.76 6     4    167   8640K  0B     0B     42052 42054 sleeping *3[2]             22.2848 10.17352   501  269991+   270     3868+      2946+      103294+    18324+     56218+      0       176       19.6  1082501253 721400427

What does this tell me?

$ pstree

showed me what triggered the process (you can also use ps aux | grep PID)

 |--= 42769 jack /usr/sbin/usernoted

 \-+= 97503 jack /Applications/iTerm.app/Contents/MacOS/iTerm2
   |-+= 98271 jack /Applications/iTerm.app/Contents/MacOS/iTerm2 --server login -fp jack
   | \-+= 98272 root login -fp jack
   |   \-+= 98273 jack -zsh
   |     \-+= 42052 jack node /Users/jack/.nvm/versions/node/v10.14.1/bin/yarn test --watch
   |       \-+- 42053 jack /bin/sh /var/folders/25/f__zt0z94vl3t812lw8zxdhw0000gn/T/yarn--1565703324137-0.6366097452477053/node /Users/jack/code/oxnotes4/node_modules/.bin/jest --watch
   |         \-+- 42054 jack /Users/jack/.nvm/versions/node/v10.14.1/bin/node /Users/jack/code/oxnotes4/node_modules/.bin/jest --watch
   |           |--- 42871 jack /Users/jack/code/oxnotes4/node_modules/node-notifier/vendor/mac.noindex/terminal-notifier.app/Contents/MacOS/terminal-notifier -actions Run again,Exit tests -closeLabel "Close" -message "-&M-T️ 1 of 29 tests failed" -title "4% Failed" -ap
   |           |--- 42891 jack /Users/jack/code/oxnotes4/node_modules/node-notifier/vendor/mac.noindex/terminal-notifier.app/Contents/MacOS/terminal-notifier -actions Run again,Exit tests -closeLabel "Close" -message "-&M-T️ 1 of 29 tests failed" -title "4% Failed" -ap
   |           \--- 43048 jack /Users/jack/code/oxnotes4/node_modules/node-notifier/vendor/mac.noindex/terminal-notifier.app/Contents/MacOS/terminal-notifier -actions Run again,Exit tests -closeLabel "Close" -message "-&M-T️ 1 of 29 tests failed" -title "4% Failed" -ap
   |-+= 42899 jack /Applications/iTerm.app/Contents/MacOS/iTerm2 --server login -fp jack

Here I can see that usernoted has a lower process number and is not a child of terminal-notifier.

Since I'm here, what do the options to ps do?

Next, how to see what is using a given (internet - thus the upcoming i option) port: $ lsof -i 3000 returns:

COMMAND   PID USER   FD   TYPE             DEVICE SIZE/OFF NODE NAME
ruby    45734 jack   11u  IPv4 0x8e82e0828a793d27      0t0  TCP *:hbci (LISTEN)

When I look up the pid it's my Rails server sure enough.

What files were opened by this process? I can see this by running $ lsof with a different option -p PROCESS_ID, i.e. $ lsof -p 42871. The output is now:

COMMAND     PID USER   FD   TYPE             DEVICE SIZE/OFF       NODE NAME
terminal- 46262 jack  cwd    DIR                1,4     1664    1493425 /Users/jack/code/oxnotes4
terminal- 46262 jack  txt    REG                1,4    87688 8644841742 /Users/jack/code/oxnotes4/node_modules/node-notifier/vendor/mac.noindex/terminal-notifier.app/Contents/MacOS/terminal-notifier
terminal- 46262 jack  txt    REG                1,4    20688 8643421167 /Library/Preferences/Logging/.plist-cache.SyHvWEnb
terminal- 46262 jack  txt    REG                1,4   239616 8643002073 /private/var/db/timezone/tz/2019b.1.0/icutz/icutz44l.dat
terminal- 46262 jack  txt    REG                1,4 27143600 8623408143 /usr/share/icu/icudt62l.dat
terminal- 46262 jack  txt    REG                1,4  3479536 8630877366 /System/Library/CoreServices/SystemAppearance.bundle/Contents/Resources/Assets.car
terminal- 46262 jack  txt    REG                1,4   107968 8630912969 /System/Library/Caches/com.apple.IntlDataCache.le.kbdx
terminal- 46262 jack  txt    REG                1,4    87744 8623404141 /usr/lib/libobjc-trampolines.dylib
terminal- 46262 jack  txt    REG                1,4  4190688 8630877390 /System/Library/CoreServices/SystemAppearance.bundle/Contents/Resources/SystemAppearance.car
terminal- 46262 jack  txt    REG                1,4  4259840 8645029523 /private/var/folders/25/f__zt0z94vl3t812lw8zxdhw0000gn/0/com.apple.LaunchServices-231-v2.csstore
terminal- 46262 jack  txt    REG                1,4   889636 8620471251 /System/Library/Keyboard Layouts/AppleKeyboardLayouts.bundle/Contents/Resources/AppleKeyboardLayouts-L.dat
terminal- 46262 jack  txt    REG                1,4   213752 8630877378 /System/Library/CoreServices/SystemAppearance.bundle/Contents/Resources/FunctionRowAppearance.car
terminal- 46262 jack  txt    REG                1,4   510848 8630877394 /System/Library/CoreServices/SystemAppearance.bundle/Contents/Resources/VibrantLightAppearance.car
terminal- 46262 jack  txt    REG                1,4  1100896 8630901776 /usr/lib/dyld
terminal- 46262 jack    0u  unix 0x8e82e0828ead6a07      0t0            ->0x8e82e0828ead7d8f
terminal- 46262 jack    1u  unix 0x8e82e0828ead648f      0t0            ->0x8e82e0828ead7e57
terminal- 46262 jack    2u  unix 0x8e82e0828ead710f      0t0            ->0x8e82e0828ead7047

Is there any thing interesting here?

For details about what kernel processes are being called, run $ dtruss -p 42871 with sudo.

Here's what I saw:

ulock_wake(0x1000002, 0x100105E00, 0x0)      = -2 0
ulock_wait(0x1010002, 0x100105E00, 0x1A02)       = 0 0
ulock_wake(0x1000002, 0x100105E00, 0x0)      = -2 0
ulock_wait(0x1010002, 0x100105E00, 0xF02)        = 0 0
ulock_wake(0x1000002, 0x100105E00, 0x0)      = -2 0
ulock_wait(0x1010002, 0x100105E00, 0x1A02)       = 0 0
ulock_wait(0x1010002, 0x100105E00, 0xF02)        = 0 0
ulock_wake(0x1000002, 0x100105E00, 0x0)      = -2 0
ulock_wait(0x1010002, 0x100105E00, 0xF02)        = 0 0
ulock_wake(0x1000002, 0x100105E00, 0x0)      = -2 0
ulock_wait(0x1010002, 0x100105E00, 0xF02)        = 0 0
ulock_wake(0x1000002, 0x100105E00, 0x0)      = -2 0
ulock_wake(0x1000002, 0x100105E00, 0x0)      = -2 0
ulock_wait(0x1010002, 0x100105E00, 0x1A02)       = 0 0
ulock_wait(0x1010002, 0x100105E00, 0xF02)        = 0 0
ulock_wake(0x1000002, 0x100105E00, 0x0)      = -2 0
ulock_wait(0x1010002, 0x100105E00, 0xF02)        = 0 0
ulock_wake(0x1000002, 0x100105E00, 0x0)      = -2 0
ulock_wait(0x1010002, 0x100105E00, 0xF02)        = 0 0
ulock_wake(0x1000002, 0x100105E00, 0x0)      = -2 0
__semwait_signal(0x1403, 0x0, 0x1)       = -1 Err#60
kevent_id(0x7F9862D589B0, 0x7000060EFB60, 0x1)       = 0 0
workq_kernreturn(0x100, 0x700006172B80, 0x1)         = 0 Err#-2
bsdthread_ctl(0x100, 0x0, 0x8007)        = 0 0
kevent_id(0x7F9862D3D430, 0x700006172610, 0x1)       = 0 0
workq_kernreturn(0x100, 0x700006172B80, 0x1)         = 0 Err#-2
kevent_id(0x7F9862D3D430, 0x700006172B80, 0x1)       = 0 0
bsdthread_ctl(0x100, 0x0, 0x8007)        = 0 0
munmap(0x102DDD000, 0x54000)         = 0 0
__semwait_signal(0x1403, 0x0, 0x1)       = -1 Err#60
kevent_id(0x7F9862D589B0, 0x7000060EFB60, 0x1)       = 0 0
workq_kernreturn(0x100, 0x700006172B80, 0x1)         = 0 Err#-2
bsdthread_ctl(0x100, 0x0, 0x8007)        = 0 0
kevent_id(0x7F9862D3D430, 0x700006172610, 0x1)       = 0 0
workq_kernreturn(0x100, 0x700006172B80, 0x1)         = 0 Err#-2
kevent_id(0x7F9862D3D430, 0x700006172B80, 0x1)       = 0 0
bsdthread_ctl(0x100, 0x0, 0x8007)        = 0 0
munmap(0x102DDD000, 0x54000)         = 0 0
__semwait_signal(0x1403, 0x0, 0x1)       = -1 Err#60
kevent_id(0x7F9862D589B0, 0x7000060EFB60, 0x1)       = 0 0
workq_kernreturn(0x100, 0x700006172B80, 0x1)         = 0 Err#-2
bsdthread_ctl(0x100, 0x0, 0x8007)        = 0 0
kevent_id(0x7F9862E7ED90, 0x700006172610, 0x1)       = 0 0
workq_kernreturn(0x100, 0x700006172B80, 0x1)         = 0 Err#-2
kevent_id(0x7F9862E7ED90, 0x700006172B80, 0x1)       = 0 0
bsdthread_ctl(0x100, 0x0, 0x8007)        = 0 0
munmap(0x102DDD000, 0x54000)         = 0 0