MacOS – chatty “switching to keychain-db” console messages in Sierra

consolekeychainmacos

In macOS Sierra I'm noticing a very "chatty" and repetitive series of warnings in the console, like this:

default 15:27:23.330990 -0700   AppleIDAuthAgent    switching to keychain-db: /Users/XYZ/Library/Keychains/login.keychain-db from /Users/XYZ/Library/Keychains/login.keychain-db (0 1 1 1)

where dozens of processes are all logging the same "switching to keychain-db" message over and over again. These messages are coming from AppleIDAuthAgent, authd, secinitd, lcd, Finder, gamed, Mail, cloudd, and on and on.

Not only that, but notice in the log message it's switching from and to the exact same file and path. The entire thing makes no sense. Anyone know what this is all about?

(Edit: As of March 2018, I'm now running High Sierra 10.13.3 and no longer are these messages appearing in my console.)

Best Answer

I wouldn't worry about chatty messages in general as the logging subsystem is now database driven and can handle thousands of messages a minute with little or no load on the system.

You can get a nice overview of your log statistics and see if this is truly one of the larger users of logging. This command does take a while to chew throat the 30 million events I have on my MacBook (3 to 5 minutes) - but even that is a trivial load on my system in practice given how optimized and power efficient Apple macOS logging is now.

log stats --overview
== archive =============================================================
size:               571,895,056 bytes
                    2,118,164,524 bytes (uncompressed)
start:              Tue Aug  1 06:33:03 2017
end:                Wed Sep 20 04:54:41 2017
statedump:          7,343

events:             [       total        log      trace   signpost ]
                    [  30,724,811 27,173,212        996    409,431 ]

activity:           [      create transition     action ]
                    [   3,132,338          0        201 ]

log messages:       [     default       info      debug      error      fault ]
                    [  26,698,888    667,559     38,352    143,035     35,805 ]

ttl:                [        1day      3days      7days     14days     30days ]
                    [     409,447 26,551,227    259,646    204,137    166,525 ]

processes:          
          [        events (%total),  decomp. bytes (%total),                           image UUID, image ]
          [    14,796,212 ( 48.2%),    983,897,959 ( 46.5%), EA3CE30B-81E9-3DEA-95F3-CDACA642C5BD, kernel ]
          [       396,296 (  1.3%),    133,190,047 (  6.3%), 5AA6AB96-6A89-3E62-9BB4-6CA2913647C9, secd ]
          [       664,086 (  2.2%),     75,896,057 (  3.6%), 99B2EC04-B281-3EBF-8541-6F6FC3273D9C, identityservicesd ]
          [       299,166 (  1.0%),     60,314,374 (  2.8%), 83FF3BD0-0A23-3232-A28A-C1A5297DA516, dasd ]
          [       727,099 (  2.4%),     53,298,516 (  2.5%), 15049F04-4C48-3D01-ABC2-8DC751F0B9E3, cloudd ]

senders:            
          [        events (%total),  decomp. bytes (%total),                           image UUID, image ]
          [    13,883,766 ( 45.2%),    943,025,476 ( 44.5%), 0086A982-E384-3ABF-AD20-BF1300E02E42, Sandbox ]
          [       394,150 (  1.3%),    133,130,846 (  6.3%), 5AA6AB96-6A89-3E62-9BB4-6CA2913647C9, secd ]
          [     1,653,215 (  5.4%),     67,618,576 (  3.2%), D7DDB735-A244-3A06-A432-135E9E368B51, CFNetwork ]
          [       294,803 (  1.0%),     60,187,838 (  2.8%), 7DC1094C-EF1A-3621-9A6B-DEDF467D64DF, DuetActivitySchedulerDaemon ]
          [       393,191 (  1.3%),     58,538,606 (  2.8%), 99B2EC04-B281-3EBF-8541-6F6FC3273D9C, identityservicesd ]

For context - this machine runs beta software often - gets beat up in all manner of ways, Xcode, buggy apps, beta versions of Microsoft Office, beta OS with enhanced logging profiles.

Related Question