Hacker News new | past | comments | ask | show | jobs | submit login

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.




Guidelines | FAQ | Support | API | Security | Lists | Bookmarklet | Legal | Apply to YC | Contact

Search: