Opened 9 years ago

Closed 9 years ago

Last modified 9 years ago

#45645 closed defect (fixed)

Registry/Sqlite operations take much longer under Yosemite

Reported by: zwaardmeester@… Owned by: macports-tickets@…
Priority: High Milestone: MacPorts 2.3.3
Component: base Version: 2.3.2
Keywords: yosemite Cc: macports@…, larryv (Lawrence Velázquez), pmetzger (Perry E. Metzger)
Port:

Description

The other day I installed VLC which has boost as a dependency. Upon deinstalling, the programs hangs at the following line:

--->  Deactivating boost @1.56.0_1+no_single+no_static+python27

I can interrupts the program here, and try again :

$ sudo port install boost
--->  Computing dependencies for boost
--->  Cleaning boost
--->  Scanning binaries for linking errors
--->  No broken files found.

$ sudo port uninstall boost
--->  Deactivating boost @1.56.0_1+no_single+no_static+python27

I can let this go on for 15 minutes but nothing changes. The following process hangs at 100% cpu: tclsh8.5

Change History (22)

comment:1 Changed 9 years ago by zwaardmeester@…

Forgot to mention, I'm on OS X 10.10 Yosemite

comment:2 Changed 9 years ago by macports@…

Same here, also on OS X 10.10 but with an older boost version:

--->  Deactivating boost @1.55.0_6+no_single+no_static+python27

comment:3 Changed 9 years ago by macports@…

Cc: macports@… added

Cc Me!

comment:4 Changed 9 years ago by ryandesign (Ryan Carsten Schmidt)

Keywords: yosemite added; deactivate deinstall removed

The boost port contains over 31,000 files, so it is understandable that it takes some time to deactivate it. If you want to deactivate it, don't interrupt it; let it take as long as it needs.

On my system:

$ sw_vers
ProductName:	Mac OS X
ProductVersion:	10.10
BuildVersion:	14A388b
$ time sudo port -f deactivate boost
--->  Unable to deactivate boost @1.56.0_1+no_single+no_static+python27+universal, the following ports depend on it:
[snip]
Warning: Deactivate forced.  Proceeding despite dependencies.
--->  Deactivating boost @1.56.0_1+no_single+no_static+python27+universal
   
real	12m17.870s
user	10m42.333s
sys	1m29.687s
$ 

During this time, tclsh8.5 is using nearly 100% of one CPU core. My system has a 2.6 GHz CPU; it'll take longer if yours is slower. My system has an SSD; it'll take longer if you have a hard disk.

This may be another manifestation of the slowness others have observed on Yosemite when running sudo port rev-upgrade. Both during rev-upgrade and during deactivate, the MacPorts registry needs to be modified for each file.

comment:5 Changed 9 years ago by zwaardmeester@…

@Ryandesign: You are right, it does eventually finish after approx. 20 minutes on my MBP. I was misled by my experience that such a relatively simple operation as uninstalling should take no longer than a few minutes or even seconds. Also I was on battery and I found the CPU usage of 100% unacceptable for such a long duration, so I figured it must be a runaway process. Clearly there is lots of room for improvement here, but I agree this is not the boost port's fault.

comment:6 Changed 9 years ago by ryandesign (Ryan Carsten Schmidt)

Component: portsbase
Port: boost removed
Summary: boost takes forever to deactivateRegistry/Sqlite operations take much longer under Yosemite

comment:7 Changed 9 years ago by neverpanic (Clemens Lang)

Unfortunately we don't really know what's going on here… there very same and SQLite database code worked perfectly fine and fast on Mavericks. It's not MacPorts' doing that this suddenly uses loads and loads of CPU cycles… if you sample the process while it runs, you'll notice it spends most of its time in sqlite3.

At the moment I assume Apple broke this due to changes in the Kernel – I didn't have time to inquire with the sqlite3 people. Feel free to contact them if you have some time.

comment:8 Changed 9 years ago by larryv (Lawrence Velázquez)

Cc: larryv@… added

Cc Me!

comment:9 Changed 9 years ago by larryv (Lawrence Velázquez)

Cc: perry@… added

Has likely duplicate #45858.

comment:10 Changed 9 years ago by pmetzger (Perry E. Metzger)

Unclear if this is related or not, but vacuuming registry.db may have sped things up for me a bit, or may not have. I didn't do a fair test. I'm mentioning it just in case.

To try the vacuum, build from source so you can get macports.sqlext around, cd to the directory with registry.db in it, "sqlite3 registry.db", ".load /path/to/macports.sqlext", then "vacuum;"

Last edited 9 years ago by pmetzger (Perry E. Metzger) (previous) (diff)

comment:11 Changed 9 years ago by larryv (Lawrence Velázquez)

comment:12 Changed 9 years ago by pmetzger (Perry E. Metzger)

The sheer length of time involved in some of this (orders of magnitude too long rather than a small multiple too long) gives me certain doubts about the query planner explanation, though I'm saying that without much of an informed opinion at all and may be completely mistaken.

comment:13 Changed 9 years ago by neverpanic (Clemens Lang)

SQL performance can degrade rapidly and by a few orders of magnitude when bad indices (or none at all) are being used (or have to be updated). This is not uncommon, especially if quadratic or cubic equations are involved.

comment:14 Changed 9 years ago by Veence (Vincent)

I am sure this whole Sqlite botch is also responsible for Apple Mail terrible performance when you try to delete more than two messages at a time. I recently purged 5000 old Macports messages from my Mailbox, it took forever to reconstruct it. Somehow, I wonder if CoreData applications are not affected too. I'll ask the question on the Cocoa dev list.

comment:15 Changed 9 years ago by pmetzger (Perry E. Metzger)

When you say you are sure, have you actually recorded the sequence of sql commands and then verified that they are in fact where the CPU is going, and that the sql queries are in fact faster on the older version of sqlite? I believe this is the only reasonable way to have certainty that the fault has been isolated.

comment:16 Changed 9 years ago by danielluke (Daniel J. Luke)

fs_usage at the time when this is happening says a lot of 'pread's are happening. I would expect that to be true if the query planner change has caused our sqlite db to be resorting to (multiple?) table scans instead of index lookups.

Clearly this needs someone to take a look further ;-)

comment:17 Changed 9 years ago by neverpanic (Clemens Lang)

Milestone: MacPorts Future
Priority: NormalHigh
Resolution: fixed
Status: newclosed

These pauses in your development cycle have been presented by SQLite. We have since terminated their sponsorship in r128113. Please report if your experience with MacPorts has improved since.

comment:18 Changed 9 years ago by pmetzger (Perry E. Metzger)

I must confess I have no idea with what "we have since terminated their sponsorship" means (or much of the rest of that).... Also, if this has been fixed by a change in the sources, I highly recommend a new Macports release happen soon, as the problem is very bad.

comment:19 in reply to:  18 Changed 9 years ago by larryv (Lawrence Velázquez)

Replying to perry@…:

I must confess I have no idea with what "we have since terminated their sponsorship" means (or much of the rest of that)

It’s a joke.

comment:20 Changed 9 years ago by pmetzger (Perry E. Metzger)

Ah. Apologies for not getting it before.

comment:21 in reply to:  18 Changed 9 years ago by neverpanic (Clemens Lang)

Replying to perry@…:

Also, if this has been fixed by a change in the sources, I highly recommend a new Macports release happen soon, as the problem is very bad.

I agree. I'd still like to wait for confirmation before merging it into the release branch though. The release needs to be done by somebody else anyway because I don't have a Apple Developer Certificate to sign the installer.

comment:22 Changed 9 years ago by jmroot (Joshua Root)

Milestone: MacPorts FutureMacPorts 2.3.3
Note: See TracTickets for help on using tickets.