Checking keychain access using Woodpile: a tutorial

Judging by the number of people who visit this blog to read articles about dealing with keychain problems, and the questions sent to me for my Genius Tips section published in MacFormat magazine, keychain problems continue to be common, and are not easily solved.

Here is a basic tutorial which shows you how to discover exactly what is happening when you start your Mac up, and it starts to bombard you with dialogs wanting passwords to unlock keychains. When you can see what is going wrong, this gives you valuable information as to what the problem really is. Note that this procedure works only in Sierra and High Sierra: if you are still running El Capitan you would need to tackle this using its log browser, the bundled Console.

You’ll also need to be running as an admin user. Although your keychain problems may have occurred when logging in or running as an ordinary user, you can only access log entries when an admin user. Log entries for all users then become accessible.

This tutorial uses my new log browser Woodpile to extract information from your Mac’s log quickly and simply. To start, download and install the latest version of Woodpile from Downloads above.

Next, ensure that you have a complete log file with your keychain problems at its start. Your Mac opens a new log file when it starts up, either from cold or as part of a restart. You need a previous complete log file to contain your keychain problems at its beginning.

  • If your keychain problems have only just started, and you haven’t shut down since, you’ll need to restart your Mac to close that log file and open a new one.
  • If your keychain problems occurred before you last started your Mac up (or restarted it), then you’ll be able to find them in a previous log file, so do not need to restart now.

keychainopen01

Open Woodpile, and click on the Make button to create a logarchive containing the keychain problems. Logarchives are quite large, often 500 MB or more, but are much better to use than the live log files. They also provide a lasting record of what happened in your logs, which can be valuable.

keychainopen02

In the open file dialog, navigate to the top level of your startup volume, then to the normally hidden folder /var/db. With that folder selected, click on the Open button.

keychainopen03

In the save file dialog, navigate to a folder in your Documents folder, for example, give your new logarchive a suitable name, then click on the Save button. Woodpile takes a few seconds to create the logarchive, and to copy all the files across to it.

keychainopen04

Once Woodpile has completed that, click on the Open button, in the open file dialog select your logarchive, and click on the Open button.

keychainopen05

Your logarchive will initially be opened in general overview, which should look something like this. You are now going to narrow the view down to look at entries in the log made by the kernel.

Tick the Show events checkbox, and select kernel from the Process popup menu. (If it doesn’t appear in that menu you can add it in Preferences, as described in Woodpile’s documentation.) Then open the Log file popup menu. You’ll notice that the first group of log files listed there have entries starting with Persist – those are the main log files, the only ones you’re interested in here. Select the lowest of those in that menu, just above the first Special entry, to open it.

There will then be a pause of a few seconds, during which Woodpile checks through that individual log file for all entries made by the kernel. As log files contain hundreds of thousands of entries, this takes a little time. The two views in the window will then change, displaying the results.

keychainopen06

You are looking for the lowest Persist log file in the Log file menu whose chart view starts with a vertical red line and a high blue bar, indicating that it begins with a startup. That should be the most recent log file with a startup, and the one to study. If you cannot find problems with keychain access in that, you can step back (working up the list of Persist log files in the popup menu) looking for the log file from the previous startup, and so on, until you find the problems occurring.

Once you have found a suitable Persist log file with a startup in this window, use the New command in the File menu to open a new window. Click on Open and open the same logarchive as in the first window. Then tick its Show events checkbox, and select accountsd in the Process popup menu. Then set its Log file popup menu to the same log file as in the first window. You then have two windows looking at the same log file, but for different processes.

The next task is to synchronise the time periods shown in the two windows, using the Period popup menu. Note the period displayed in the chart view of the kernel window. In the accountsd window, see if that time interval is offered in the Period popup menu. If it’s not, select the kernel window, click once on the first bar in its chart view to zoom in, then right-click (two-finger tap on a trackpad) anywhere on the chart view to zoom back out again. Switch back to the accountsd window, and you should now see that as an option in the Period menu. Select it for accountsd.

keychainopen07

Your final task is to view the log entries from accountsd for the startup period. In the accountsd window, Command-click on the first and highest bar, with the red line at its left, to zoom in and display log entries. Slide the view divider across to the right and adjust the window to make it easier to read the log entries in which keychains are opened, or not, which are highlighted here.

keychainopen08

You should see something like the following, which I have edited down for clarity:
18:08:44.887260 [com.apple.securityd.atomicfile] 0x7fc6c9736d10 opened /Users/hoakley/Library/Keychains/login.keychain-db: 1646112 bytes
18:08:44.895637 [com.apple.securityd.atomicfile] 0x7fc6c9525450 opened /Users/hoakley/Library/Keychains/loginMPro.keychain-db: 549908 bytes
18:08:44.899788 [com.apple.securityd.atomicfile] 0x7fc6c973a4b0 opened /Users/hoakley/Library/Application Support/Adobe/AIR/ELS/com.adobe.formscentral.FormsCentralForAcrobat/PrivateEncryptedDatak: 22384 bytes
18:08:44.902467 [com.apple.securityd.atomicfile] 0x7fc6c97512a0 opened /Library/Keychains/System.keychain: 170992 bytes

This states exactly which keychains have been opened at login: in this case, it includes the standard ~/Keychains/login.keychain-db, another older user keychain named loginMPro.keychain-db in the same folder, a hidden Adobe keychain required for its app support, and the System keychain at /Library/Keychains/System.keychain.

You may also see errors, such as:
18:10:02.657007 [com.apple.securityd.security_exception] UNIX error exception: 17
which in this case is not relevant, but should make it clear what is going wrong with your current keychain setup.

To preserve those log entries, you can select, copy and paste them into a text document in another app, or click on the Save Data button to write them out to a text file.