#63068 closed defect (fixed)
base: performance: operations slower in 2.7.x vs. 2.6.4: reclaim, clean
Reported by: | mascguy (Christopher Nielsen) | Owned by: | mascguy (Christopher Nielsen) |
---|---|---|---|
Priority: | Normal | Milestone: | |
Component: | base | Version: | 2.7.1 |
Keywords: | Cc: | jmroot (Joshua Root), l2dy (Zero King) | |
Port: |
Description (last modified by mascguy (Christopher Nielsen))
I've noticed that the two operations mentioned - reclaim and clean - are noticeably slower with MacPorts 2.7.x vs. 2.6.4.
Per some discussion with Josh, we believe there haven't been any notable changes to these operations for the 2.7.x releases, so they should perform similarly to v2.6.4.
The standard disclaimer applies: As I'm running on an ancient 2008-era MacPro, I'm far more likely to notice things like this vs. 99% of our users. Nonetheless, if there is a performance regression - and it can be identified and resolved - it will be to everyone's benefit.
In terms of the approach: We'll enable TCL profiling, and generate results for each of the operations (reclaim and clean), across both v2.6.4 and v2.7.1. To ensure we're comparing apples-to-apples, that will be done via a cloned VM, with an identical set of installed ports. The operations will also be run twice, with the first run done to prime the filesystem cache. The 2nd run will include profiling enabled.
This should be very straightforward: It's simply a matter of generating results, upgrading MacPorts, and repeating the process. Once done, I'll attach the various profiler outputs for analysis.
Thoughts/comments welcome, as always.
Attachments (8)
Change History (25)
comment:1 Changed 3 years ago by mascguy (Christopher Nielsen)
Component: | ports → base |
---|
comment:2 Changed 3 years ago by mascguy (Christopher Nielsen)
comment:3 Changed 3 years ago by mascguy (Christopher Nielsen)
While I'm still working on generating profiler results, the following timings illustrate the problem. These were run in a macOS 10.12 VM, though the specific macOS release doesn't matter; they're consistent across versions.
Operation | Time: 2.6.4 | Time: 2.7.1 |
---|---|---|
port reclaim | 25.4 secs | 50.2 secs |
port clean --all installed | 28.7 secs | 54.1 secs |
Interestingly enough, the processing time is nearly doubled for 2.7.x, vs. 2.6.4.
Is it possible we made a change - inadvertent or otherwise - which results in the various logic running twice for each operation?
That doesn't appear to be the case based on debug-level logging, and seems a bit far-fetched. But it would certainly explain the doubling in total processing time.
comment:4 Changed 3 years ago by mascguy (Christopher Nielsen)
Description: | modified (diff) |
---|---|
Summary: | base: performance: operations slower in 2.7.x vs. 2.6.4: reclaim, rev-upgrade, clean → base: performance: operations slower in 2.7.x vs. 2.6.4: reclaim, clean |
comment:5 Changed 3 years ago by mascguy (Christopher Nielsen)
Description: | modified (diff) |
---|
Changed 3 years ago by mascguy (Christopher Nielsen)
Attachment: | port-profile-reclaim-mp-2.6.x.txt added |
---|
Changed 3 years ago by mascguy (Christopher Nielsen)
Attachment: | port-profile-reclaim-mp-2.7.x.txt added |
---|
comment:6 Changed 3 years ago by mascguy (Christopher Nielsen)
Attached profiler output for port reclaim
; filenames:
- port-profile-reclaim-mp-2.6.x.txt
- port-profile-reclaim-mp-2.7.x.txt
Changed 3 years ago by mascguy (Christopher Nielsen)
Attachment: | port-profile-clean-mp-2.6.x.txt added |
---|
Changed 3 years ago by mascguy (Christopher Nielsen)
Attachment: | port-profile-clean-mp-2.7.x.txt added |
---|
comment:7 Changed 3 years ago by mascguy (Christopher Nielsen)
Attached profiler output for port clean --all installed
; filenames:
- port-profile-clean-mp-2.6.x.txt
- port-profile-clean-mp-2.7.x.txt
comment:8 Changed 3 years ago by mascguy (Christopher Nielsen)
Re-profiled both operations, to obtain proc-based timings.
Switched to the following TCL wrapper, to avoid having to modify MacPorts itself:
#!/opt/local/libexec/macports/bin/tclsh8.5 package require profiler proc ::exit {} { puts stderr "Exit call intercepted" } puts stderr "Profiler - Init" ::profiler::init if {[catch { [source /opt/local/bin/port] } result_or_errormsg]} { #handle error } else { #normal processing } puts stderr "Profiler - Done" puts stderr [::profiler::sortFunctions exclusiveRuntime]
Changed 3 years ago by mascguy (Christopher Nielsen)
Attachment: | port-procprofile-clean-mp-2.6.x.txt added |
---|
Changed 3 years ago by mascguy (Christopher Nielsen)
Attachment: | port-procprofile-clean-mp-2.7.x.txt added |
---|
Changed 3 years ago by mascguy (Christopher Nielsen)
Attachment: | port-procprofile-reclaim-mp-2.6.x.txt added |
---|
Changed 3 years ago by mascguy (Christopher Nielsen)
Attachment: | port-procprofile-reclaim-mp-2.7.x.txt added |
---|
comment:9 Changed 3 years ago by mascguy (Christopher Nielsen)
Proc-based timing results attached; filenames:
- port-procprofile-reclaim-mp-2.6.x.txt
- port-procprofile-reclaim-mp-2.7.x.txt
- port-procprofile-clean-mp-2.6.x.txt
- port-procprofile-clean-mp-2.7.x.txt
comment:10 Changed 3 years ago by mascguy (Christopher Nielsen)
Josh, I'm done at this point, unless any profiling refinements are needed.
When you get a chance, take a look at the profiler results, and let me know your thoughts.
comment:11 follow-up: 12 Changed 3 years ago by jmroot (Joshua Root)
It looks like the main difference is likely something running in the portfile interpreter, so that's where you would need to profile, like in #56793.
comment:12 Changed 3 years ago by mascguy (Christopher Nielsen)
comment:13 Changed 3 years ago by mascguy (Christopher Nielsen)
Wow, can't believe it's been seven weeks since last working on this. I'll add this to top of my work backlog, to ensure it doesn't languish.
comment:14 Changed 3 years ago by l2dy (Zero King)
Cc: | l2dy added |
---|
comment:15 Changed 2 years ago by mascguy (Christopher Nielsen)
Resolution: | → fixed |
---|---|
Status: | assigned → closed |
Given the various fixes and improvements in 2.7.x - along with further pending changes for 2.8.x - we're in good shape. Closing as fixed.
comment:16 follow-up: 17 Changed 2 years ago by jmroot (Joshua Root)
Are you seeing better port clean
performance? I know reclaim was improved, though not by undoing any change that 2.7 made.
comment:17 Changed 17 months ago by mascguy (Christopher Nielsen)
Replying to jmroot:
Are you seeing better
port clean
performance? I know reclaim was improved, though not by undoing any change that 2.7 made.
My primary Mac is slightly faster now - upgraded to a MacPro 2012 last year, vs. a 2008 previously - and the latter is currently out-of-commission. (Need to purchase another AMD Metal-compatible GPU, as the current one moved into the 2012.)
But a better test platform might be my old 2006-era MacBookPro. So at some point I'll install 2.64 in a separate prefix, run some timing tests, and compare to our latest 2.8.x release. Stay tuned!
Details for operation
reclaim
: The check for unused distfiles is the key area where I've noticed the most slowdown. And interestingly enough, immediately running a 2nd iteration - with a potential benefit from a primed filesystem cache - doesn't yield much of an improvement. So something is coming into play.