Hacker News Reader

Comment by carguy1983 | Hacker News Reader

carguy1983

I have an 8-way Xeon Mac Pro w/ 20GB of RAM, almost half of which is 'free' at any point during the day unless I'm doing something really out of the ordinary.

Yet it still swaps to disk ALL THE TIME and a new Terminal.app window can take up to 5 seconds to open.

I really don't give a shit how it's not "technically" broken - that's broken from an experience point of view. And I haven't re-installed the OS (this was an App Store upgrade from Snow leopard) because that's a major pain in the ass as this is an actual workstation used to do actual work.

I can't believe this is actually advice, either - that's what Windows users used to say in the 90s. Anyway, I guess I'm just ranting. OS X is wonderful except for the fact that it sucks at managing memory to keep a system snappy.

View on HN

Yet it still swaps to disk ALL THE TIME and a new Terminal.app window can take up to 5 seconds to open.

That's not swapping. That delay is /usr/bin/login searching the system logs so that it can display the date and time of your last login.

Create a .hushlogin file in your home directory to prevent that.

Two other things that can make OSX terminal launching slow:

1. The default use of /usr/libexec/path_helper to manage your $PATH.[1]

2. An accumulation of log files in /var/log/asl.[2]

For (1), I just edit /etc/profile and disable path_helper altogether. I set the PATH manually. (This also allows me to put /usr/local/bin before /usr/bin, which is my preference. I've never understood Apple's default settings for $PATH. They put /usr/local/bin later - which defeats the whole point of installing, say, a newer vim in there.) For (2), a cron or launchd job can take care of it.

[1]: http://mjtsai.com/blog/2009/04/01/slow-opening-terminal-wind...

[2]: http://osxdaily.com/2010/05/06/speed-up-a-slow-terminal-by-c...

time /usr/libexec/path_helper PATH="/usr/bin:/bin:/usr/sbin:/sbin:/usr/local/bin:/usr/X11/bin:/usr/local/share/python:/usr/local/sbin:/Users/stefan/bin"; export PATH;

real 0m0.004s user 0m0.001s sys 0m0.002s

Really? Are you sure path_helper slows things down?

> Are you sure path_helper slows things down?

I'm sure that it did, but not sure that it does. The code you ran isn't quite what /etc/profile does. Here's a run of that on an older machine where I work (see below on versions):

    $ time eval `/usr/libexec/path_helper -s`

    real	0m0.106s
    user	0m0.084s
    sys	        0m0.021s

However, looking at my current machine, I realize that /usr/libexec/path_helper is no longer a shell script at all. It's compiled. Running that same test on a newer machine, I get this:

    $ time eval `/usr/libexec/path_helper -s`

    real	0m0.004s
    user	0m0.001s
    sys  	0m0.003s

So, in a nutshell, I think you're right for current machines: The path_helper advice looks to be out of date. I can't edit my original answer any more, but thanks for making me rethink this (I've been annoyed by slow-opening terminals in OSX for years. Apparently, they worked on this part of the problem.)

You're not crazy -- path_helper used to be godawful slow. It used to be a shell script with exponential (IIRC) time complexity in the number of components in your path. It could very easily add a huge delay to your launch time.

No. The sequence of events concerning this in login:

0) `login -pf`

1) quietlog = 0

2) if ("-q" in argv) quietlog = 1

3) if (!quietlog) getlastlogxbyname(&lastlog)

4) if (!quietlog) quietlog = access(".hushlogin") == 0

5) dolastlog(quietlog) ->

6) if (!quietlog) printf(lastlog)

You can see from this that the "searching the system logs" (which, to be clear, is going to be really really fast: /var/run/utmpx is a small file with fixed length fields) happens in step #3, before .hushlogin is checked in step #4.

If you wish to verify, you can read the code at the following URL. Note that __APPLE__ and USE_PAM are defined for the OS X distribution of this code, while LOGIN_CAP is not.

http://opensource.apple.com/source/system_cmds/system_cmds-5...

It does not use /var/run/utmpx anymore.

Look at the code for getlastlogxbyname(). It does an ASL query for last login, and that's the source of the delay.

http://www.opensource.apple.com/source/Libc/Libc-763.12/gen/...

As I stated, that cannot be the source of the delay, because getlastlogxbyname is called based on a check of quietlog before quietlog is updated to take into account .hushlogin. With the exception of step #7, all of this code is inside of a single function (main), which makes it very easy to verify that the sequence of events I'm describing is correct. (I will happily believe you, however, that getlastlogxbyname is internally now using something horrendously slow to look up that information.)

(edit: I have gone ahead and verified your statements regarding getlastlogxbyname now being based on ASL. Using that knowledge, and based on st3fan's comments about the output of dtrace, I then used dtruss to verify my own assertion regarding the order of events. The result: .hushlogin in fact only affects the output of "last login"; it does not keep login from getting that information in the first place with ASL. To keep it from doing so you must pass -q, something Terminal does not do.)

You're right. ASL is the source of the slowdown, but .hushlogin isn't actually doing anything to solve the problem.

The correct way to bypass the ASL query is to set Terminal to open shells with /bin/bash (or your shell of choice) instead of the default login shell. Terminal will still use /usr/bin/login to launch the shell, but it passes the -q switch to prevent the ASL query.

When I dug into the source code a couple of months ago, I inadvertently made both changes (Terminal settings and .hushlogin). Clearly it's the Terminal settings that solved the problem and not .hushlogin. Thanks for clearing it up.

Saurik, using dtrace I do see something touching about 50 logs in /var/log/asl every time in login. I wonder where that comes from. I don't think it is getlastlogxbyname() or dolastlog().

As thought_alarm states, getlastlogxbyname may not be accessing utmpx anymore (I have not myself checked); however, the behavior of that function cannot be affected by .hushlogin, as it is called before .hushlogin is checked. All of this logic (excepting step #7) happens within a single function (main), so it is very simple to see the flow.

(edit: I have gone ahead and checked: thought_alarm is correct, in that getlastlogxbyname is now using ASL instead of utmpx; however, I have also verified my sequencing assertion with dtrace: .hushlogin has no effect on the usage of ASL, but manually passing -q to login does: it thereby cannot be the source of a .hushlogin-mediated delay.)

But why does .hushlogin makes Terminal.app come alive faster?

As I cannot replicate this behavior, I am not certain. On my OS X 10.6.8 11" Air, terminal sessions are only being delayed by my 2.5MB .bash_history; if I clear that file ( something I sadly wouldn't want to always do ;P) terminals come up with almost no delay.

However, assuming that is the case for some people, we have to look elsewhere than the last login lookup. There are only a few other usages of quietlog: motd (open file, read it), mail (check environment, stat file), and pam_silent.

The first two are not going to cause any kind of performance issue, so we have to look at pam_silent. This variable is particularly interesting, as it is only set to 0 if -q is not passed (and it is not) and there is no .hushlogin (it is not directly controlled by quietlog).

If it is not 0, then it is left at a default value, which is PAM_SILENT, and is passed to almost every single PAM function. It could very well be that there is some crazy-slow logic in PAM that is activated if you do not set PAM_SILENT.

Given this, someone experiencing this issue might look through the code for PAM to see if anything looks juicy (and this is something that will best be done by someone with this problem, as it could be that they have some shared trait, such as "is using LDAP authentication").

(edit: FWIW, I looked through OpenPAM, and I am not certain I see any actual checks against PAM_SILENT at all; the only mentions of it are for parameter verification: the library makes certain you don't pass unknown flag bits to anything.)

Wow, I'd forgotten how long ago I'd done this:

  kore:~$ ls -l .hushlogin
  -rw-r--r--  1 jay  staff  0 Aug 15  2002 .hushlogin

> "That delay is /usr/bin/login searching the system logs so that it can display the date and time of your last login."

Am I missing something? `w` on my linux system takes well below one second:

  [burgerbrain@eeepc] ~ % time w   
  14:11:18 up 19:41,  6 users,  load average: 0.27, 0.10, 0.14
  USER     TTY      FROM              LOGIN@   IDLE   JCPU   PCPU WHAT
  REDACTED
  w  0.01s user 0.05s system 61% cpu 0.096 total

I can't imagine why anything like that would ever take anywhere near 5 seconds.

That shows your currently active login, which is of course in main memory. Your most recent login may well no longer be active, and so you have to search the log files.

Ah yeah, had a brain fart there. Even so, `last` is similarly fast.

You sir are a gentleman and scholar. As a laptop user with only 8 GB of RAM and a slow non-SSD hard disk, this one trick just made my day! Thanks.

Only 8GB? ha. I have 4GB and having any kind of flash player open in chrome means I have no RAM free.

Really? Because I have 2GB too and I can have several flash videos open and get along just fine with other programs.

If you are interested what happens when you open a new terminal window, run 'sudo opensnoop' in one window and then open a new window.

Here the majority of files being opened are in /var/log or Homebrew related.

Also interesting ... creating a .hushlogin did not change much. It still opens about 50 files in /var/log/asl/

Awesome! Thanks for pointing out opensnoop!

It's painful guessing how many hours of my life I could have back if only I had known about this before. Thanks for the pain, thought_alarm.

When the logs are read once, they should stay in the VFS cache as long as there is enough RAM, shouldn't they?

Anyway, instead of running /usr/bin/login, I just use /bin/zsh as my Terminal.app startup command which is much faster.

However, every time I access the file system, even some tab for autocompletion, it takes a few seconds. Even cd'ing into some directory can sometimes take a few seconds. Sometimes ~= it's more than 1h ago that I accessed that dir or so.

Edit: Maybe it's Time Machine or Spotlight or so which destroys the effectiveness of the VFS cache?

Changing directory is instant for me. (no SSD here, all spinning rust.) Tab completion is instant too. Run Time Machine every hour, never made a change to the spotlight config.

anything that hits the disk heavily, including time machine, kills my snow leopard machine. lack of ui responsiveness, beachballs et al.

I know I shouldn't say it (a dozen have already done so), but thank you. Just wonderful. My terminal just got 10 times better. I'd make it 'best comment of the month' if I could.

> That delay is /usr/bin/login searching the system logs > so that it can display the date and time of your last login.

Normally Unixes (Linux included) use a pretty efficient binary file called wtmp for that, I'm surprised if OS X doesn't. Reading the last disk block of that file would contain the last login with overwhelming probability.

There has to be a lot of seeks even on a slow laptop rotating hd to get a 5 second delay, with 15 ms seek time you get 333 seeks in 5 secs.

OS X does: /var/run/utmpx.

So it takes 5 seconds to search the system logs for the date of the last login? How is this any less broken?

It isn't broken from a memory management point of view, which is what the post being discussed is talking about, I think is the point.

Wow, I'm really surprised this isn't default behavior. Knowing when you last logged in isn't nearly useful enough to justify the delay it so routinely causes.

It's worth it when you realize someone else has been logging on as you over the weekend.

Well, I suppose it seems sillier on a laptop than on a desktop.

or a server...

Well sure, but I wasn't saying that it should be default behavior for Mac OS X server or server-aimed n*x distros. I don't think that most people are using non-server Mac OS X as a remote server, and those who are could override the default.

But then you can't trust the logs.

I want to reach across the internet and hug you right now.

Wow, thank you for this. The delay caused by this behavior has been driving me crazy for a really long time.

Hard drives can read read data sequentially very, very quickly. On whatever generic SATA hard drive I have in my workstation, I get:

  eklitzke@gnut:~ $ time sudo head -c 1073741824 /dev/sda > /dev/null
  
  real	0m8.267s
  user	0m0.220s
  sys	0m0.810s

So I can read 1G off the drive in about 8 seconds.

Even if the login command does need to sequentially read through logs to find the last login time (and I'm skeptical of that, because that would be a stupid way to implement login), I don't see how that would explain multiple seconds of waiting.

Log files are not stored sequentially on disk because they are constantly being appended to.

http://en.wikipedia.org/wiki/File_system_fragmentation

Is it possible that power-saver is spinning down the hard-disk?

Fantastic. Thanks for that.

Wow - that does make a difference in launching a terminal!

relatedly, i call "`eval resize`" in my .zshrc--any idea why that takes ~5s if it's more than a minute or two since i last did it, but is instantaneous otherwise? (yes, i'm certain that it's that line that's taking time--if i start typing during the delay before the prompt shows up, i get a resize error about unrecognized characters and then a couple bits of random ANSI on my input.)

Thanks for this. I love learning something simple, new, useful, and that I probably should have already known after decades writing software.

Thanks a ton! This has been really bothering me lately. I could not figure out what was causing such a delay.

Doesn't OSX rotate logs? Seems weird that it should take so long.

I'd send you a dollar if I could for this post. Awesome.

Does this apply to iTerm as well?

You can change your profile to not launch a new login shell for each window/terminal, but that might cause other issues.

Yes

HALLELUJAH. Thanks.

> I haven't re-installed the OS (this was an App Store upgrade from Snow leopard) because that's a major pain in the ass as this is an actual workstation used to do actual work.

This has never been hard to do on OS X since 10.0 because they followed the Unix convention of separating user data from system files. It is, of course, rarely necessary unless you've used superuser access to seriously muck with things under /System.

I've done this repeatedly over the years when dealing with beta releases & system migrations and it's never taken much longer than the time needed to copy the files.

"Yet it still swaps to disk ALL THE TIME "

You should run some dtrace magic to find out what 'it' is. MIght be the OS, might be a badly behaving application. Who knows.

I find it too easy to blame the OS for all of this. One poorly written app can cause a lot of performance damage.

Putting an SSD in for me solved all the problems you mentioned. Haven't seen a beach ball since.

Lion has probably been optimized for SSD since Apple is quickly getting rid of spinning disks in their entire line up.

> Yet it still swaps to disk ALL THE TIME

Is it actively paging to disk at times when there is plenty of free RAM? A common complaint on Linux is "I've closed a lot of stuff but it is still using swap" because even if the pages are read back into RAM when next used they are kept in the swap area in case they need to go out again (that way they don't need to be written unless changed, saving some I/O).

Under Linux you can see how much is found in both RAM and on disk with the "SwapCached" entry in /proc/meminfo - it won't stop counting those pages as present in the swap areas until either it runs out of never used swap space so needs to overwrite then to page out other pages or the page is changes in memory (at which point the copy on disk is stale so can not be reused without being updated anyway).

> and a new Terminal.app window can take up to 5 seconds to open.

Have you monitored system activity at such times to see where the delay is? While it could be due to unnecessary disk I/O it could also be elsewhere such as delayed DNS lookups if anything in your profile scripts does such a thing and there is an issue with your connectivity or DNS configuration.

(I'm not an OS X user and never have been so sorry if these thoughts are irrelevant - but I'm guessing memory management in OS X is similar enough for knowledge of how Linux plays the game not to be completely useless)

I disable swap on all my machines over 4gb... Windows, Linux, or OSX. There are people who will advise against this, but in 5 years I've not had any problems. I think once or twice firefox leaked uncontrollably and therefore killed.

Not sure what my settings are now, but I used to keep swap off on my Windows machine (especially while playing games, since swapping kills gaming performance).

I can't believe this is actually advice, either - that's what Windows users used to say in the 90s.

At least Windows, having gone through this particular growing pain, is nowadays fairly painless to reinstall. Did OSX ever improve that aspect of their product?

1) It's never been "hard" to reinstall OS X. What was difficult last time you tried?

2) The OS reinstall path is identical to the OS upgrade path, making it very well tested. This has been the case since (IIRC) Snow Leopard.

3) The latest few generations of hardware can even (re)install the OS over the internet, meaning you don't even need to carry around media to reinstall. (Assuming you're on a fast connection or are willing to wait.)

It's entirely painless to reinstall OS X.

Yes. I reinstalled OS X on a couple machines do to various issues. I was extremely surprised at how nice the experience is. When I logged back in after the reinstall, Chrome even reopened with my old tabs in it.

Not sure if that is a good or a bad thing. Would really really annoy me, tough. If I reinstall an OS, I do it because I want a clean plate, everything back to "standard". Opening my old tabs in my browser tells me, that it kept various config/temp files, which is probably what I wanted to get rid of.

If you want to lose all of your user settings, create a new user account and nuke the old one.

If you want to replace various bits of the system, reinstall the OS.

These are different scenarios with different use-cases, and I'd argue it's a much worse idea to conflate the behaviours, as in certain other OSes, than OS X's fault for properly treating them as separate operations.

User and System files are separate in Unix.

It's a good thing.

Reply on news.ycombinator.com