macOS Performance Monitoring: Collection

Update Feb 21, 2020:
  * Added --show-process-io command to examples to collect disk usage info.
  * Adjusted regex to parse pageins, bytes_read, and bytes_written

Luckily Apple has provided a handy tool called powermetrics to help get some baseline statistics about just how much a process or group of processes are affecting the performance of your mac.

This command collects a lot of information about each process running on your mac but the most important metric will be the “energy impact” score macOS gives to each process.

What does the energy impact score mean and how is it calculated?

Per Apple’s public documentation here energy impact is:

Energy Impact: A relative measure of the current energy consumption of the app. Lower numbers are better.

https://support.apple.com/en-us/HT201464

The additional research I have done says that energy impact is calculated on CPU %, CPU power draw, GPU usage, whether or not an app has any power assertions (pmset -g assertions) to keep the computer or screen active, memory usage, and network usage.

True to its name, energy impact seems to be a decent measure of the impact an app or process has on the computer both in “feel” and in battery usage rates.

How do I collect energy impact information via the command line?

Here is the terminal command that will collect statistics for all processes running on your machine every 15 seconds and write the output to a file in the /tmp/ directory.

/usr/bin/powermetrics -a 0 -i 15000 -s tasks --show-process-io --show-process-energy -u /tmp/powermetrics.log
# -a 0                      Don't display summary line, not useful in this case
# -i 15000                  Collect data every 15 seconds
# -s tasks                  Focus on per-process information
# --show-process-io         Add disk i/o and pageins to results
# --show-process-energy     Show energy impact scores
# -u /tmp/powermetrics.log  Output to file location

We have since moved to more advanced ways to collect energy impact and performance telemetry for cmdReporter’s internal testing, but I have run the above command as a LaunchDaemon on my own machine for months at a time without noticing any additional overhead.

Notes for Analyzing Data

1. If the application you are testing uses a kernel extension be sure to chart kernel_task with that KEXT loaded and without that KEXT loaded.
2. Use some analysis tool like Splunk, Kibana, or event Excel instead of trying to read the logs manually.
3. Create a repeatable testing plan so you can change variables and maintain data integrity. A simple example would be: “reboot, immediately run target application, perform X task in target application, stop log collection”
4. Compare native processes like WindowServer, Safari, and Mail to the target application. This will give you relative performance statistics to help determine the qualitative “feel” and “slowness” an application may be causing.

Powermetrics as a LaunchDaemon

Here is the LaunchDaemon plist that I have been using to collect this information in the background on my test machines.

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
	<key>KeepAlive</key>
	<true/>
	<key>Label</key>
	<string>com.cmdsec.cmdreporter.energyimpact.logger</string>
	<key>LowPriorityBackgroundIO</key>
	<true/>
	<key>ProgramArguments</key>
	<array>
		<string>/usr/bin/powermetrics</string>
		<string>-a</string>
		<string>0</string>
		<string>-i</string>
		<string>15000</string>
		<string>-s</string>
		<string>tasks</string>
		<string>--show-process-energy</string>
                <string>--show-process-io</string>
		<string>-u</string>
		<string>/tmp/powermetrics.log</string>
	</array>
	<key>RunAtLoad</key>
	<true/>
</dict>
</plist>

Splunk regex for parsing powermetrics logs

This regex should be portable to other log analysis tools if they conform to the PCRE regex standard but I have only tested this on Splunk. Once all the data is broken out into fields you can easily chart CPU and energy impact broken out by individual processes.

index="your_index_here" sourcetype=generic_single_line
| rex field="_raw" "(?P<process_name>^[\w \(\)\-\.]+)(\b|\))\s{3,}(?P<pid>[\d]+)\s+(?P<cpu_ms_s>[\d\.]+)\s+(?P<percent_cpu_user>[\d\.]+)\s+(?P<deadlines_lt_2ms>[\d\.]+)\s+(?P<deadlines_2_to_5ms>[\d\.]+)\s+(?P<wakeups>[\d\.]+)\s+(?P<intr_pkg_idle>[\d\.]+)\s+(?P<bytes_read>[\d\.]+)\s+(?P<bytes_written>[\d\.]+)\s+(?P<pageins>[\d\.]+)\s+(?P<energy_impact>[\d\.]+)"

Up Next…

In the next performance monitoring post we’ll dive deeper into how to chart and make sense of the data we have collected in this post.