How to check what is preventing MBP from graceful shutdown/restart and fix it? [Now with log entries]

Complementing other answers …


Observe verbose mode during restart or shut down

Mac OS X: How to start up in single-user or verbose mode

– if you start in verbose mode, then restart or shut down will be similarly verbose.

Hint: if things in verbose mode seem to not progress beyond a certain point, allow maybe five minutes before either:

  • forcing a restart (Command-Control-power); or
  • forcing a shutdown (press and hold the power key).

If a forced restart does not succeed, that could be another clue to the cause of the problem(s).

A related question, albeit not problem-oriented: Can anyone interpret verbose shutdown messages?

The problem-oriented case here should be easier to resolve for lupincho. Fewer tea leaves.

To start in verbose mode without keying Command-V

A preference can be stored in NVRAM. Enter the following command in Terminal, and be prepared to enter your admin password:

sudo nvram boot-args="-v"

The next start of the system will be verbose.


sysdiagnose

Before each restart or shutdown, in Terminal:

sudo sysdiagnose

It's time consuming, but you need not investigate the results of all runs. Pay attention only if a problems arises.

For a case such as lupincho's:

  • the run of sysdiagnose may reveal a problem before a restart or shut down
  • the end result of sysdiagnose may be of interest following a forced restart or shut down.

More specifically: if a run of sysdiagnose fails to progress beyond a certain point, knowing that point can help to gain a sense of the underlying problem.

During the run you can use the following key combination, repeatedly, to see whether things are progressing:

  • Control-T

For the allmemory part of the sysdiagnose routine, Apple's two minute estimate may be wildly inaccurate. Be patient.

If you suspect that sysdiagnose fails to progress beyond a certain point, then key:

  • Control-C

If repeated use of Control-C fails to abort sysdiagnose, then (in my experience with Mountain Lion) it's almost certain that an attempt to restart or shut down the operating system will fail.


Shutdown monitoring

In Finder, go to:

/private/var/log/shutdown_monitor.log

This file is typically empty, but may contain items of interest following a problematic shutdown. (I have little experience in this area.)

If the only stray process at shutdown is WindowServer

It's not unusual to have stray processes at shutdown. A stray can be problematic only if it is not killed.

If you suspect that WindowServer is not killed, and that this particular stray is contributory to shutdown failure: ask yourself whether any third party software makes nonstandard use of the WindowServer process.

Quick Look of a GrabFS view of WindowServer on Mountain Lion, with two displays:

enter image description here

If Lion is similar, then my gut feeling is that the cause of shutdown failures lies beyond WindowServer.


Guesswork, based upon results of launchctl

Whilst the machine is running normally, what response to the following command?

sudo launchctl list | grep  --invert-match com.apple

Wonder whether any non-Apple software is contributory to the problem. Anti-virus, anti-malware software?


Following an upgrade from Lion to Mountain Lion

Aim for:

/private/var/log/com.apple.launchd/launchd-shutdown.system.log

It seems the default is one log per shut down, with a maximum of two so there's also:

/private/var/log/com.apple.launchd/launchd-shutdown.system.log.1

Following any forced restart or forced shut down, you might choose to set aside a copy of the most recent of the two. If force is required on any more than one occasion, you can compare files to see whether a pattern emerges.

Generally

Don't rule out the possibility of an issue with third party software, even release quality. Little Snitch may be well written and widely respected but:

  • when problems such as the one in this question become extended or too puzzling, any non-Apple kernel extension deserves attention.

I tested Build 12A269 of OS X 10.8 for around two weeks before it was released, with particular attention to shut down behaviours in difficult situations. Whilst I have not watched any videos from WWDC 2012, I do have a sense that Apple has worked very hard to prevent the need for force in all but the most difficult situations.

Building upon David DelMonte's answer

At least on Mountain Lion, I see the load of Little Snitch 3.0 Preview 2 (3857) very early – before shutdown logging begins. If things relating to this KEXT are similarly late around shutdown time, then maybe an issue will be not evident in the usual log files on disk.


If ever you discover the cause of the problem – with either Lion or Mountain Lion – I'll be pleased to know.

In the meantime, with big thanks for the bounty, a closing thought:

kextstat -l | grep --invert-match com.apple

Go to Applications -> Utilities, and open Console

Take a look at the system.log file, you might be able to find something there.


pmset -g assertions gets a summary of power assertions:

$ pmset -g assertions
Assertion status system-wide:
   PreventUserIdleDisplaySleep             0
   CPUBoundAssertion                       0
   DisableInflow                           0
   ChargeInhibit                           0
   PreventSystemSleep                      0
   PreventUserIdleSystemSleep              1
   ExternalMedia                           1
   DisableLowPowerBatteryWarnings          0
   EnableIdleSleep                         1
   NoRealPowerSources_debug                0
   UserIsActive                            0
   ApplePushServiceTask                    0

Listed by owning process:
  pid 153: [0x00000099012c023b] PreventUserIdleSystemSleep named: "com.apple.audio.'AppleUSBAudioEngine:Apple Inc.:Display Audio:15261930:2,1'.noidlesleep" 
  pid 19: [0x00000013012c0235] ExternalMedia named: "com.apple.powermanagement.externalmediamounted" 

You can see the path of a process with ps up $pid:

$ ps up 153
USER          PID  %CPU %MEM      VSZ    RSS   TT  STAT STARTED      TIME COMMAND
_coreaudiod   153   0.0  0.2  2475000   6740   ??  Ss   Fri05PM  12:17.71 /usr/sbin/coreaudiod

I've used to have this problem and did find a fix that worked for me. Although I'm not directly answering your question (how to check what's causing the problem), it's a fix that might be worth a shot:

  1. Navigate to "Macintosh HD > Library"
  2. Delete the folder named "Java"
  3. Empty Trash
  4. Shut down
  5. Once you run anything Java-related, you will be prompted to reinstall Java, do that.

After that, shutdown time should improve. Note: I'm still getting slow shutdowns when I shutdown immediately after the system starts, so after you follow the steps and want to test, wait a few minutes after the system starts before shutting down.