salt-minion causing slow bootup on OS X 10.9 and 10.10

[Jesse Mcconathy]

I have been using Salt to manage Mac clients for about a year now, and we have had this persistent issue, with 10.9 (and it is affecting 10.10 as well) Macs, that appears to be caused by the ‘salt-minion’ which causes the client to take around 5 minutes to boot.  The issue seems to start after the machine is bound to my Windows AD domain.  10.8 machines do not have this issue using the same settings. 

If an affected machine is told to disable the salt-minion, it will boot fine, just under a minute.  I have compared logs, but cannot see anything that is obviously related to salt, though my Salt and Mac knowledge are not extensive.

In my most recent round of troubleshooting, I have set up a machine that pulls from a new branch on my salt-master and the only enabled feature is ‘apps.salt-minion’ in the salt/top.sls file.  I have manually bound the machine to my domain, and pulled system logs (posted below).

Unsuccessful troubleshooting and the result:

- We have tried setting the master as the IP address rather than the domain name, in the minion file.  no change

- Set ‘RunAtLoad’ to false in the minion plist file.  System boot would be fine, but user log-in would then take 4 minutes.

- Added the ‘-d’ key to the minion to launch it as a daemon. No change

- Added the ‘retry_dns: 0’ option per https://github.com/saltstack/salt/pull/2507 . No change

- Updated a test client with local master to the latest release of salt. no change

- Added a static entry for 'salt' in the '/etc/hosts' file.  no change

my salt versions report:

Salt: 2014.1.1

Python: 2.7.5 (default, Mar  9 2014, 22:15:05)

Jinja2: 2.7.2

M2Crypto: 0.22

msgpack-python: 0.4.1

msgpack-pure: Not Installed

pycrypto: 2.6

PyYAML: 3.10

PyZMQ: 14.0.1

ZMQ: 4.0.5

System.log file (from boot to login):

Nov  4 15:07:46 localhost bootlog[0]: BOOT_TIME 1415135266 0

Nov  4 15:07:55 localhost syslogd[20]: Configuration Notice:

ASL Module "com.apple.appstore" claims selected messages.

Those messages may not appear in standard system log files or in the ASL database.

Nov  4 15:07:55 localhost syslogd[20]: Configuration Notice:

ASL Module "com.apple.authd" sharing output destination "/var/log/system.log" with ASL Module "com.apple.asl".

Output parameters from ASL Module "com.apple.asl" override any specified in ASL Module "com.apple.authd".

Nov  4 15:07:55 localhost syslogd[20]: Configuration Notice:

ASL Module "com.apple.authd" claims selected messages.

Those messages may not appear in standard system log files or in the ASL database.

Nov  4 15:07:55 localhost syslogd[20]: Configuration Notice:

ASL Module "com.apple.bookstore" claims selected messages.

Those messages may not appear in standard system log files or in the ASL database.

Nov  4 15:07:55 localhost syslogd[20]: Configuration Notice:

ASL Module "com.apple.eventmonitor" claims selected messages.

Those messages may not appear in standard system log files or in the ASL database.

Nov  4 15:07:55 localhost syslogd[20]: Configuration Notice:

ASL Module "com.apple.install" claims selected messages.

Those messages may not appear in standard system log files or in the ASL database.

Nov  4 15:07:55 localhost syslogd[20]: Configuration Notice:

ASL Module "com.apple.iokit.power" claims selected messages.

Those messages may not appear in standard system log files or in the ASL database.

Nov  4 15:07:55 localhost syslogd[20]: Configuration Notice:

ASL Module "com.apple.mail" claims selected messages.

Those messages may not appear in standard system log files or in the ASL database.

Nov  4 15:07:55 localhost syslogd[20]: Configuration Notice:

ASL Module "com.apple.MessageTracer" claims selected messages.

Those messages may not appear in standard system log files or in the ASL database.

Nov  4 15:07:55 localhost syslogd[20]: Configuration Notice:

ASL Module "com.apple.performance" claims selected messages.

Those messages may not appear in standard system log files or in the ASL database.

Nov  4 15:07:55 localhost syslogd[20]: Configuration Notice:

ASL Module "com.apple.securityd" claims selected messages.

Those messages may not appear in standard system log files or in the ASL database.

Nov  4 15:07:58 --- last message repeated 6 times ---

Nov  4 15:07:55 localhost kernel[0]: Longterm timer threshold: 1000 ms

Nov  4 15:07:55 localhost kernel[0]: PMAP: PCID enabled

Nov  4 15:07:55 localhost kernel[0]: Darwin Kernel Version 13.4.0: Sun Aug 17 19:50:11 PDT 2014; root:xnu-2422.115.4~1/RELEASE_X86_64

Nov  4 15:07:55 localhost kernel[0]: vm_page_bootstrap: 1974635 free pages and 106133 wired pages

Nov  4 15:07:55 localhost kernel[0]: kext submap [0xffffff7f807a9000 - 0xffffff8000000000], kernel text [0xffffff8000200000 - 0xffffff80007a9000]

Nov  4 15:07:55 localhost kernel[0]: zone leak detection enabled

Nov  4 15:07:55 localhost kernel[0]: "vm_compressor_mode" is 4

Nov  4 15:07:55 localhost kernel[0]: standard timeslicing quantum is 10000 us

Nov  4 15:07:55 localhost kernel[0]: standard background quantum is 2500 us

Nov  4 15:07:55 localhost kernel[0]: mig_table_max_displ = 74

Nov  4 15:07:55 localhost kernel[0]: TSC Deadline Timer supported and enabled

Nov  4 15:07:55 localhost kernel[0]: AppleACPICPU: ProcessorId=1 LocalApicId=0 Enabled

Nov  4 15:07:55 localhost kernel[0]: AppleACPICPU: ProcessorId=2 LocalApicId=2 Enabled

Nov  4 15:07:55 localhost kernel[0]: AppleACPICPU: ProcessorId=3 LocalApicId=1 Enabled

Nov  4 15:07:55 localhost kernel[0]: AppleACPICPU: ProcessorId=4 LocalApicId=3 Enabled

Nov  4 15:07:55 localhost kernel[0]: AppleACPICPU: ProcessorId=5 LocalApicId=255 Disabled

Nov  4 15:07:55 localhost kernel[0]: AppleACPICPU: ProcessorId=6 LocalApicId=255 Disabled

Nov  4 15:07:55 localhost kernel[0]: AppleACPICPU: ProcessorId=7 LocalApicId=255 Disabled

Nov  4 15:07:55 localhost kernel[0]: AppleACPICPU: ProcessorId=8 LocalApicId=255 Disabled

Nov  4 15:07:55 localhost kernel[0]: calling mpo_policy_init for TMSafetyNet

Nov  4 15:07:55 localhost kernel[0]: Security policy loaded: Safety net for Time Machine (TMSafetyNet)

Nov  4 15:07:55 localhost kernel[0]: calling mpo_policy_init for Sandbox

Nov  4 15:07:55 localhost kernel[0]: Security policy loaded: Seatbelt sandbox policy (Sandbox)

Nov  4 15:07:55 localhost kernel[0]: calling mpo_policy_init for Quarantine

Nov  4 15:07:55 localhost kernel[0]: Security policy loaded: Quarantine policy (Quarantine)

Nov  4 15:07:55 localhost kernel[0]: Copyright (c) 1982, 1986, 1989, 1991, 1993

Nov  4 15:07:55 localhost kernel[0]: The Regents of the University of California. All rights reserved.

Nov  4 15:07:55 localhost kernel[0]: MAC Framework successfully initialized

Nov  4 15:07:55 localhost kernel[0]: using 16384 buffer headers and 10240 cluster IO buffer headers

Nov  4 15:07:55 localhost kernel[0]: AppleKeyStore starting (BUILT: Aug 17 2014 20:21:39)

Nov  4 15:07:55 localhost kernel[0]: IOAPIC: Version 0x20 Vectors 64:87

Nov  4 15:07:55 localhost kernel[0]: ACPI: sleep states S3 S4 S5

Nov  4 15:07:55 localhost kernel[0]: pci (build 20:04:33 Aug 17 2014), flags 0x63008, pfm64 (36 cpu) 0xf80000000, 0x80000000

Nov  4 15:07:55 localhost kernel[0]: AppleIntelCPUPowerManagement: Turbo Ratios 0057

Nov  4 15:07:55 localhost kernel[0]: AppleIntelCPUPowerManagement: (built 20:17:40 Aug 17 2014) initialization complete

Nov  4 15:07:55 localhost kernel[0]: [ PCI configuration begin ]

Nov  4 15:07:55 localhost kernel[0]: console relocated to 0xf80010000

Nov  4 15:07:55 localhost kernel[0]: [ PCI configuration end, bridges 13, devices 18 ]

Nov  4 15:07:55 localhost kernel[0]: FireWire (OHCI) TI ID 823f built-in now active, GUID a4b197fffeb8124e; max speed s800.

Nov  4 15:07:55 localhost kernel[0]: mcache: 4 CPU(s), 64 bytes CPU cache line size

Nov  4 15:07:55 localhost kernel[0]: mbinit: done [96 MB total pool size, (64/32) split]

Nov  4 15:07:55 localhost kernel[0]: Pthread support ABORTS when sync kernel primitives misused

Nov  4 15:07:55 localhost kernel[0]: rooting via boot-uuid from /chosen: 725D66C6-BF47-3EF4-9FE3-5B1E64DB2859

Nov  4 15:07:55 localhost kernel[0]: Waiting on <dict ID="0"><key>IOProviderClass</key><string ID="1">IOResources</string><key>IOResourceMatch</key><string ID="2">boot-uuid-media</string></dict>

Nov  4 15:07:55 localhost kernel[0]: com.apple.AppleFSCompressionTypeZlib kmod start

Nov  4 15:07:55 localhost kernel[0]: com.apple.AppleFSCompressionTypeLZVN kmod start

Nov  4 15:07:55 localhost kernel[0]: com.apple.AppleFSCompressionTypeDataless kmod start

Nov  4 15:07:55 localhost kernel[0]: com.apple.AppleFSCompressionTypeZlib load succeeded

Nov  4 15:07:55 localhost kernel[0]: com.apple.AppleFSCompressionTypeLZVN load succeeded

Nov  4 15:07:55 localhost kernel[0]: com.apple.AppleFSCompressionTypeDataless load succeeded

Nov  4 15:07:55 localhost kernel[0]: AppleIntelCPUPowerManagementClient: ready

Nov  4 15:07:55 localhost kernel[0]: Got boot device = IOService:/AppleACPIPlatformExpert/PCI0@0/AppleACPIPCI/SATA@1F,2/AppleIntelPchSeriesAHCI/PRT0@0/IOAHCIDevice@0/AppleAHCIDiskDriver/IOAHCIBlockStorageDevice/IOBlockStorageDriver/Hitachi HTS727575A9E362 Media/IOGUIDPartitionScheme/Macintosh HD@2

Nov  4 15:07:55 localhost kernel[0]: BSD root: disk0s2, major 1, minor 2

Nov  4 15:07:55 localhost kernel[0]: BTCOEXIST off 

Nov  4 15:07:55 localhost kernel[0]: BRCM tunables:

Nov  4 15:07:55 localhost kernel[0]: pullmode[1] txringsize[  256] txsendqsize[1024] reapmin[   32] reapcount[  128]

Nov  4 15:07:55 localhost kernel[0]: Thunderbolt Self-Reset Count = 0xedefbe00

Nov  4 15:07:55 localhost kernel[0]: hfs: mounted TEST9 on device root_device

Nov  4 15:07:55 localhost kernel[0]: USBF:    7.262    AppleUSBEHCI::Found a transaction which hasn't moved in 5000 milliseconds on bus 0xfd, timing out! (Addr: 6, EP: 0)

Nov  4 15:07:47 localhost com.apple.launchd[1]: *** launchd[1] has started up. ***

Nov  4 15:07:47 localhost com.apple.launchd[1]: *** Shutdown logging is enabled. ***

Nov  4 15:07:55 localhost distnoted[19]: # distnote server daemon  absolute time: 9.915787162   civil time: Tue Nov  4 15:07:55 2014   pid: 19 uid: 0  root: yes

Nov  4 15:07:55 localhost kernel[0]: IO80211Controller::dataLinkLayerAttachComplete():  adding AppleEFINVRAM notification

Nov  4 15:07:55 localhost kernel[0]: IO80211Interface::efiNVRAMPublished():  

Nov  4 15:07:55 localhost com.apple.SecurityServer[14]: Session 100000 created

Nov  4 15:07:58 localhost kernel[0]: flow_divert_kctl_disconnect (0): disconnecting group 1

Nov  4 15:07:58 localhost kernel[0]: init

Nov  4 15:07:58 localhost kernel[0]: probe

Nov  4 15:07:58 localhost kernel[0]: start

Nov  4 15:07:58 localhost kernel[0]: [IOBluetoothHCIController][start] -- completed

Nov  4 15:07:58 localhost com.apple.SecurityServer[14]: Entering service

Nov  4 15:07:58 localhost kernel[0]: SMC::smcReadKeyAction ERROR: smcReadData8 failed for key LsNM (kSMCKeyNotFound)

Nov  4 15:07:58 localhost kernel[0]: SMC::smcReadKeyAction ERROR LsNM kSMCKeyNotFound(0x84) fKeyHashTable=0x0

Nov  4 15:07:58 localhost kernel[0]: SMC::smcGetLightshowVers ERROR: smcReadKey LsNM failed (kSMCKeyNotFound)

Nov  4 15:07:58 localhost kernel[0]: SMC::smcPublishLightshowVersion ERROR: smcGetLightshowVers failed (kSMCKeyNotFound)

Nov  4 15:07:58 localhost kernel[0]: SMC::smcInitHelper ERROR: smcPublishLightshowVersion failed (kSMCKeyNotFound)

Nov  4 15:07:58 localhost kernel[0]: Previous Shutdown Cause: 5

Nov  4 15:07:58 localhost kernel[0]: SMC::smcInitHelper ERROR: MMIO regMap == NULL - fall back to old SMC mode

Nov  4 15:07:58 localhost kernel[0]: IOBluetoothUSBDFU::probe

Nov  4 15:07:58 localhost kernel[0]: IOBluetoothUSBDFU::probe ProductID - 0x8281 FirmwareVersion - 0x0131

Nov  4 15:07:58 localhost kernel[0]: **** [IOBluetoothHostControllerUSBTransport][start] -- completed -- result = TRUE -- 0xbc00 ****

Nov  4 15:07:58 localhost kernel[0]: **** [BroadcomBluetoothHostControllerUSBTransport][start] -- Completed -- 0xbc00 ****

Nov  4 15:07:58 localhost kernel[0]: [IOBluetoothHCIController][staticBluetoothHCIControllerTransportShowsUp] -- Received Bluetooth Controller register service notification -- 0xbc00 

Nov  4 15:07:58 localhost kernel[0]: [IOBluetoothHCIController::setConfigState] calling registerService

Nov  4 15:07:58 localhost kernel[0]: **** [IOBluetoothHCIController][protectedBluetoothHCIControllerTransportShowsUp] -- Connected to the transport successfully -- 0xf200 -- 0xb000 -- 0xbc00 ****

Nov  4 15:07:58 localhost UserEventAgent[11]: Failed to copy info dictionary for bundle /System/Library/UserEventPlugins/alfUIplugin.plugin

Nov  4 15:07:58 localhost UserEventAgent[11]: Captive: CNPluginHandler en1: Inactive

Nov  4 15:07:58 localhost kernel[0]: Waiting for DSMOS...

Nov  4 15:07:59 localhost kernel[0]: DSMOS has arrived

Nov  4 15:07:59 localhost kernel[0]: AirPort: Link Down on en1. Reason 8 (Disassociated because station leaving).

Nov  4 15:07:59 CAS-14300 configd[18]: setting hostname to "CAS-14300"

Nov  4 15:07:59 CAS-14300 configd[18]: network changed.

Nov  4 15:08:00 CAS-14300 kernel[0]: en2: promiscuous mode enable succeeded

Nov  4 15:08:00 CAS-14300 awacsd[72]: Starting awacsd connectivity_executables-97.1 (Jul 27 2014 17:02:42)

Nov  4 15:08:00 CAS-14300 awacsd[72]: InnerStore CopyAllZones: no info in Dynamic Store

Nov  4 15:08:00 CAS-14300 hidd[60]: void __IOHIDPlugInLoadBundles(): Loaded 0 HID plugins

Nov  4 15:08:00 CAS-14300 hidd[60]: Posting 'com.apple.iokit.hid.displayStatus' notifyState=1

Nov  4 15:08:00 CAS-14300 aosnotifyd[75]: aosnotifyd has been launched

Nov  4 15:08:00 CAS-14300 airportd[76]: airportdProcessDLILEvent: en1 attached (up)

Nov  4 15:08:00 CAS-14300 kernel[0]: createVirtIf(): ifRole = 1

Nov  4 15:08:00 CAS-14300 kernel[0]: in func createVirtualInterface ifRole = 1

Nov  4 15:08:00 CAS-14300 kernel[0]: AirPort_Brcm4331_P2PInterface::init name <p2p0> role 1

Nov  4 15:08:00 CAS-14300 kernel[0]: AirPort_Brcm4331_P2PInterface::init() <p2p> role 1

Nov  4 15:08:00 CAS-14300 kernel[0]: Created virtif 0xffffff801f467800 p2p0

Nov  4 15:08:00 CAS-14300 kernel[0]: VM Swap Subsystem is ON

Nov  4 15:08:00 CAS-14300 loginwindow[55]: Login Window Application Started

Nov  4 15:08:01 CAS-14300 digest-service[82]: label: default

Nov  4 15:08:01 CAS-14300 digest-service[82]: dbname: od:/Local/Default

Nov  4 15:08:01 CAS-14300 digest-service[82]: mkey_file: /var/db/krb5kdc/m-key

Nov  4 15:08:01 CAS-14300 digest-service[82]: acl_file: /var/db/krb5kdc/kadmind.acl

Nov  4 15:08:01 CAS-14300 digest-service[82]: digest-request: uid=0

Nov  4 15:08:01 CAS-14300 mDNSResponder[52]: mDNSResponder mDNSResponder-522.92.1 (Jul 27 2014 17:31:49) starting OSXVers 13

Nov  4 15:08:01 CAS-14300 digest-service[82]: digest-request: netr probe 1

Nov  4 15:08:01 CAS-14300 digest-service[82]: digest-request: init request

Nov  4 15:08:01 CAS-14300 configd[18]: network changed.

Nov  4 15:08:01 CAS-14300 configd[18]: network changed: DNS*

Nov  4 15:08:01 CAS-14300 mDNSResponder[52]: D2D_IPC: Loaded

Nov  4 15:08:01 CAS-14300 mDNSResponder[52]: D2DInitialize succeeded

Nov  4 15:08:01 CAS-14300 mDNSResponder[52]:   4: Listening for incoming Unix Domain Socket client requests

Nov  4 15:08:01 CAS-14300 com.apple.usbmuxd[38]: usbmuxd-344.3 on Oct 13 2014 at 21:10:09, running 64 bit

Nov  4 15:08:01 CAS-14300 networkd[101]: networkd.101 built Aug 24 2013 22:08:46

Nov  4 15:08:01 CAS-14300 systemkeychain[78]: done file: /var/run/systemkeychaincheck.done

Nov  4 15:08:02 CAS-14300 mds[51]: (Warning) Server: No stores registered for metascope "kMDQueryScopeComputer"

Nov  4 15:08:02 CAS-14300 sandboxd[87] ([84]): rpcsvchost(84) deny file-read-data /private/var/root/Library/Preferences/.GlobalPreferences.plist

Nov  4 15:08:02 CAS-14300 mdmclient[53]: ApplePushService: Timed out making blocking call, failed to perform call via XPC connection to 'com.apple.apsd'

Nov  4 15:08:03 CAS-14300 mDNSResponder[52]: mDNS_Register_internal: ERROR!! Tried to register AuthRecord 00007F904B007B60 CAS-14300.local. (Addr) that's already in the list

Nov  4 15:08:03 CAS-14300 mDNSResponder[52]: mDNS_Register_internal: ERROR!! Tried to register AuthRecord 00007F904B007FF0 1.0.0.127.in-addr.arpa. (PTR) that's already in the list

Nov  4 15:08:03 CAS-14300 mDNSResponder[52]: mDNS_Register_internal: ERROR!! Tried to register AuthRecord 00007F904C003D60 CAS-14300.local. (AAAA) that's already in the list

Nov  4 15:08:03 CAS-14300 mDNSResponder[52]: mDNS_Register_internal: ERROR!! Tried to register AuthRecord 00007F904C0041F0 1.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa. (PTR) that's already in the list

Nov  4 15:08:03 CAS-14300 UserEventAgent[11]: Registered Workstation service - CAS-14300 [3c:07:54:4b:d7:df]._workstation._tcp.

Nov  4 15:08:03 CAS-14300 digest-service[82]: digest-request: init return domain: UNT server: CAS-14300 indomain was: <NULL>

Nov  4 15:08:03 CAS-14300 WindowServer[85]: Server is starting up

Nov  4 15:08:03 CAS-14300 WindowServer[85]: Session 256 retained (2 references)

Nov  4 15:08:03 CAS-14300 WindowServer[85]: Session 256 released (1 references)

Nov  4 15:08:03 CAS-14300 mdmclient[53]: ApplePushService: Timed out making blocking call, failed to perform call via XPC connection to 'com.apple.apsd'

Nov  4 15:08:03 CAS-14300 mds[51]: (Normal) FMW: FMW 0 0

Nov  4 15:08:03 CAS-14300 WindowServer[85]: Session 256 retained (2 references)

Nov  4 15:08:03 CAS-14300 WindowServer[85]: init_page_flip: page flip mode is on

Nov  4 15:08:03 CAS-14300 locationd[57]: Incorrect NSStringEncoding value 0x8000100 detected. Assuming NSASCIIStringEncoding. Will stop this compatiblity mapping behavior in the near future.

Nov  4 15:08:03 CAS-14300 locationd[57]: NBB-Could not get UDID for stable refill timing, falling back on random

Nov  4 15:08:03 CAS-14300 kernel[0]: **** [IOBluetoothHostControllerUSBTransport][SuspendDevice] -- Suspend -- suspendDeviceCallResult = 0x0000 (kIOReturnSuccess) -- 0xbc00 ****

Nov  4 15:08:03 CAS-14300 locationd[57]: Location icon should now be in state 'Inactive'

Nov  4 15:08:04 CAS-14300 kernel[0]: Ethernet [AppleBCM5701Ethernet]: Link up on en0, 1-Gigabit, Full-duplex, Symmetric flow-control, Debug [796d,2301,0de1,0300,cde1,3800]

Nov  4 15:08:04 CAS-14300 apsd[74]: CGSLookupServerRootPort: Failed to look up the port for "com.apple.windowserver.active" (1102)

Nov  4 15:08:04 CAS-14300 mdmclient[53]: ApplePushService: Timed out making blocking call, failed to perform call via XPC connection to 'com.apple.apsd'

Nov  4 15:08:05 CAS-14300 configd[18]: network changed: v4(en0+:10.120.33.25) DNS+ Proxy+ SMB+

Nov  4 15:08:05 CAS-14300 WindowServer[85]: Found 60 modes for display 0x00000000 [60, 0]

Nov  4 15:08:05 CAS-14300 WindowServer[85]: Found 1 modes for display 0x00000000 [1, 0]

Nov  4 15:08:05 --- last message repeated 2 times ---

Nov  4 15:08:05 CAS-14300 WindowServer[85]: mux_initialize: Couldn't find any matches

Nov  4 15:08:05 CAS-14300 WindowServer[85]: Found 60 modes for display 0x00000000 [60, 0]

Nov  4 15:08:05 CAS-14300 mdmclient[53]: ApplePushService: Timed out making blocking call, failed to perform call via XPC connection to 'com.apple.apsd'

Nov  4 15:08:15 --- last message repeated 2 times ---

Nov  4 15:08:15 CAS-14300 awacsd[72]: Exiting

Nov  4 15:08:15 CAS-14300 kernel[0]: pci pause: SDXC

Nov  4 15:08:23 CAS-14300 kernel[0]: AppleBCM5701Ethernet [en0]:       44        f receivePackets - got vlan packet

Nov  4 15:08:54 CAS-14300 apsd[74]: Reporting com.apple.main-thread is hung

Nov  4 15:08:54 CAS-14300 spindump[119]: CGSLookupServerRootPort: Failed to look up the port for "com.apple.windowserver.active" (1102)

Nov  4 15:08:54 CAS-14300 spindump[119]: Unable to register Stop Spinning port: 1011

Nov  4 15:08:54 CAS-14300 spindump[119]: CGSLookupServerRootPort: Failed to look up the port for "com.apple.windowserver.active" (1102)

Nov  4 15:09:28 --- last message repeated 1 time ---

Nov  4 15:09:28 CAS-14300 spindump[120]: CGSLookupServerRootPort: Failed to look up the port for "com.apple.windowserver.active" (1102)

Nov  4 15:09:28 CAS-14300 spindump[120]: Unable to register Stop Spinning port: 1011

Nov  4 15:09:28 CAS-14300 spindump[120]: CGSLookupServerRootPort: Failed to look up the port for "com.apple.windowserver.active" (1102)

Nov  4 15:09:30 CAS-14300 warmd[37]: [warmctl_evt_timer_bc_activation_timeout:287] BC activation bcstop timer fired!

Nov  4 15:09:50 CAS-14300 spindump[120]: CGSLookupServerRootPort: Failed to look up the port for "com.apple.windowserver.active" (1102)

Nov  4 15:10:28 CAS-14300 spindump[121]: CGSLookupServerRootPort: Failed to look up the port for "com.apple.windowserver.active" (1102)

Nov  4 15:10:28 CAS-14300 spindump[121]: Unable to register Stop Spinning port: 1011

Nov  4 15:10:28 CAS-14300 spindump[121]: CGSLookupServerRootPort: Failed to look up the port for "com.apple.windowserver.active" (1102)

Nov  4 15:11:21 --- last message repeated 1 time ---

Nov  4 15:12:04 CAS-14300 kernel[0]: kauth external resolver timed out (1 timeout(s) of 60 seconds).

Nov  4 15:12:04 CAS-14300 locationd[57]: could not create path /var/folders/zz/zyxvpxvq6csfxvn_n00000sm00006d/C/

Nov  4 15:12:29 CAS-14300 spindump[125]: CGSLookupServerRootPort: Failed to look up the port for "com.apple.windowserver.active" (1102)

Nov  4 15:12:29 CAS-14300 spindump[125]: Unable to register Stop Spinning port: 1011

Nov  4 15:12:29 CAS-14300 spindump[125]: CGSLookupServerRootPort: Failed to look up the port for "com.apple.windowserver.active" (1102)

Nov  4 15:12:41 CAS-14300 spindump[125]: Got xpc error message in libspindump client connection: Connection invalid

Nov  4 15:12:41 CAS-14300 com.apple.launchd[1] (com.apple.opendirectoryd[21]): Exited with code: 70

Nov  4 15:12:41 CAS-14300 apsd[74]: CGSLookupServerRootPort: Failed to look up the port for "com.apple.windowserver.active" (1102)

Nov  4 15:12:41 CAS-14300 WindowServer[85]: Found 1 modes for display 0x00000000 [1, 0]

Nov  4 15:12:41 --- last message repeated 2 times ---

Nov  4 15:12:41 CAS-14300 WindowServer[85]: WSMachineUsesNewStyleMirroring: false

Nov  4 15:12:41 CAS-14300 WindowServer[85]: Display 0x2b102294: GL mask 0x1; bounds (0, 0)[1920 x 1080], 60 modes available

Main, Active, on-line, enabled, boot, Vendor 10ac, Model 404b, S/N 31353055, Unit 0, Rotation 0

UUID 0x3eb3e3e2ef40e5ac9de4f16df391224c

Nov  4 15:12:41 CAS-14300 WindowServer[85]: Display 0x003f0040: GL mask 0x10; bounds (0, 0)[4096 x 2160], 2 modes available

off-line, enabled, Vendor ffffffff, Model ffffffff, S/N ffffffff, Unit 4, Rotation 0

UUID 0xffffffffffffffffffffffffffffffff

Nov  4 15:12:41 CAS-14300 WindowServer[85]: Display 0x003f003f: GL mask 0x8; bounds (0, 0)[0 x 0], 1 modes available

off-line, enabled, Vendor ffffffff, Model ffffffff, S/N ffffffff, Unit 3, Rotation 0

UUID 0xffffffffffffffffffffffffffffffff

Nov  4 15:12:41 CAS-14300 WindowServer[85]: Display 0x003f003e: GL mask 0x4; bounds (0, 0)[0 x 0], 1 modes available

off-line, enabled, Vendor ffffffff, Model ffffffff, S/N ffffffff, Unit 2, Rotation 0

UUID 0xffffffffffffffffffffffffffffffff

Nov  4 15:12:41 CAS-14300 WindowServer[85]: Display 0x003f003d: GL mask 0x2; bounds (0, 0)[0 x 0], 1 modes available

off-line, enabled, Vendor ffffffff, Model ffffffff, S/N ffffffff, Unit 1, Rotation 0

UUID 0xffffffffffffffffffffffffffffffff

Nov  4 15:12:41 CAS-14300 WindowServer[85]: WSSetWindowTransform: Singular matrix

Nov  4 15:12:41 --- last message repeated 2 times ---

Nov  4 15:12:41 CAS-14300 WindowServer[85]: Display 0x2b102294: GL mask 0x1; bounds (0, 0)[1920 x 1080], 60 modes available

Main, Active, on-line, enabled, boot, Vendor 10ac, Model 404b, S/N 31353055, Unit 0, Rotation 0

UUID 0x3eb3e3e2ef40e5ac9de4f16df391224c

Nov  4 15:12:41 CAS-14300 WindowServer[85]: Display 0x003f0040: GL mask 0x10; bounds (2944, 0)[1 x 1], 2 modes available

off-line, enabled, Vendor ffffffff, Model ffffffff, S/N ffffffff, Unit 4, Rotation 0

UUID 0xffffffffffffffffffffffffffffffff

Nov  4 15:12:41 CAS-14300 WindowServer[85]: Display 0x003f003f: GL mask 0x8; bounds (2945, 0)[1 x 1], 1 modes available

off-line, enabled, Vendor ffffffff, Model ffffffff, S/N ffffffff, Unit 3, Rotation 0

UUID 0xffffffffffffffffffffffffffffffff

Nov  4 15:12:41 CAS-14300 WindowServer[85]: Display 0x003f003e: GL mask 0x4; bounds (2946, 0)[1 x 1], 1 modes available

off-line, enabled, Vendor ffffffff, Model ffffffff, S/N ffffffff, Unit 2, Rotation 0

UUID 0xffffffffffffffffffffffffffffffff

Nov  4 15:12:41 CAS-14300 WindowServer[85]: Display 0x003f003d: GL mask 0x2; bounds (2947, 0)[1 x 1], 1 modes available

off-line, enabled, Vendor ffffffff, Model ffffffff, S/N ffffffff, Unit 1, Rotation 0

UUID 0xffffffffffffffffffffffffffffffff

Nov  4 15:12:41 CAS-14300 WindowServer[85]: CGXPerformInitialDisplayConfiguration

Nov  4 15:12:41 CAS-14300 WindowServer[85]:   Display 0x2b102294: Unit 0; Vendor 0x10ac Model 0x404b S/N 825569365 Dimensions 20.91 x 11.73; online enabled, Bounds (0,0)[1920 x 1080], Rotation 0, Resolution 1

Nov  4 15:12:41 CAS-14300 WindowServer[85]:   Display 0x003f0040: Unit 4; Vendor 0xffffffff Model 0xffffffff S/N -1 Dimensions 0.00 x 0.00; offline enabled, Bounds (2944,0)[1 x 1], Rotation 0, Resolution 1

Nov  4 15:12:41 CAS-14300 WindowServer[85]:   Display 0x003f003f: Unit 3; Vendor 0xffffffff Model 0xffffffff S/N -1 Dimensions 0.00 x 0.00; offline enabled, Bounds (2945,0)[1 x 1], Rotation 0, Resolution 1

Nov  4 15:12:41 CAS-14300 WindowServer[85]:   Display 0x003f003e: Unit 2; Vendor 0xffffffff Model 0xffffffff S/N -1 Dimensions 0.00 x 0.00; offline enabled, Bounds (2946,0)[1 x 1], Rotation 0, Resolution 1

Nov  4 15:12:41 CAS-14300 WindowServer[85]:   Display 0x003f003d: Unit 1; Vendor 0xffffffff Model 0xffffffff S/N -1 Dimensions 0.00 x 0.00; offline enabled, Bounds (2947,0)[1 x 1], Rotation 0, Resolution 1

Nov  4 15:12:41 CAS-14300 WindowServer[85]: GLCompositor: GL renderer id 0x01021b06, GL mask 0x0000001f, accelerator 0x000039cb, unit 0, caps QEX|MIPMAP, vram 256 MB

Nov  4 15:12:41 CAS-14300 WindowServer[85]: GLCompositor: GL renderer id 0x01021b06, GL mask 0x0000001f, texture max 16384, viewport max {16384, 16384}, extensions FPRG|NPOT|GLSL|FLOAT

Nov  4 15:12:41 CAS-14300 WindowServer[85]: GLCompositor enabled for tile size [256 x 256]

Nov  4 15:12:41 CAS-14300 WindowServer[85]: CGXGLInitMipMap: mip map mode is on

Nov  4 15:12:42 CAS-14300 loginwindow[55]: **DMPROXY** Found `/System/Library/CoreServices/DMProxy'.

Nov  4 15:12:42 CAS-14300 ntpd[106]: proto: precision = 1.000 usec

Nov  4 15:12:43 CAS-14300 WindowServer[85]: Display 0x2b102294: Unit 0; ColorProfile { 2, "DELL G2410"}; TransferFormula (1.000000, 1.000000, 1.000000)

Nov  4 15:12:43 CAS-14300 launchctl[140]: com.apple.findmymacmessenger: Already loaded

Nov  4 15:12:43 CAS-14300 com.apple.SecurityServer[14]: Session 100004 created

Nov  4 15:12:43 CAS-14300 UserEventAgent[142]: Failed to copy info dictionary for bundle /System/Library/UserEventPlugins/alfUIplugin.plugin

Nov  4 15:12:43 CAS-14300 loginwindow[55]: Login Window Started Security Agent

Nov  4 15:12:43 CAS-14300 mds[51]: (Normal) Volume: volume:0x7fa19500a000 ********** Bootstrapped Creating a default store:0 SpotLoc:(null) SpotVerLoc:(null) occlude:0 /Volumes/firmwaresyncd.bG2N0y

Nov  4 15:12:43 CAS-14300 SecurityAgent[148]: This is the first run

Nov  4 15:12:43 CAS-14300 SecurityAgent[148]: MacBuddy was run = 0

Nov  4 15:12:43 CAS-14300 WindowServer[85]: MPAccessSurfaceForDisplayDevice: Set up page flip mode on display 0x2b102294 device: 0x7f82aae0b7d0  isBackBuffered: 1 numComp: 3 numDisp: 3

Nov  4 15:12:43 CAS-14300 WindowServer[85]: _CGXGLDisplayContextForDisplayDevice: acquired display context (0x7f82aae0b7d0) - enabling OpenGL

Nov  4 15:12:44 CAS-14300 WindowServer[85]: **DMPROXY** (2) Found `/System/Library/CoreServices/DMProxy'.

Nov  4 15:12:44 CAS-14300 WindowServer[85]: Display 0x2b102294: Unit 0; ColorProfile { 2, "DELL G2410"}; TransferFormula (1.000000, 1.000000, 1.000000)

Nov  4 15:12:46 --- last message repeated 1 time ---

Nov  4 15:12:46 CAS-14300 WindowServer[85]: 3891612: App SecurityAgent cannot order in untagged windows before login.

Nov  4 15:12:46 CAS-14300 SecurityAgent[148]: CGSOrderWindowList

Nov  4 15:12:50 CAS-14300 SecurityAgent[148]: User info context values set for rpurvis

Nov  4 15:12:50 CAS-14300 SecurityAgent[148]: Login Window login proceeding

Nov  4 15:12:51 CAS-14300 loginwindow[55]: Login Window - Returned from Security Agent

Nov  4 15:12:51 CAS-14300 loginwindow[55]: USER_PROCESS: 55 console

Nov  4 15:12:51 CAS-14300 kernel[0]: AppleKeyStore:Sending lock change 0

Nov  4 15:12:51 CAS-14300 com.apple.launchd.peruser.502[200]: Background: Aqua: Registering new GUI session.

Nov  4 15:12:51 CAS-14300 com.apple.launchd.peruser.502[200] (com.apple.EscrowSecurityAlert): Unknown key: seatbelt-profiles

Nov  4 15:12:51 CAS-14300 com.apple.launchd.peruser.502[200] (com.apple.ReportCrash): Falling back to default Mach exception handler. Could not find: com.apple.ReportCrash.Self

Nov  4 15:12:51 CAS-14300 launchctl[203]: com.apple.pluginkit.pkd: Already loaded

Nov  4 15:12:51 CAS-14300 launchctl[203]: com.apple.sbd: Already loaded

Nov  4 15:12:51 CAS-14300 distnoted[205]: # distnote server agent  absolute time: 305.271886430   civil time: Tue Nov  4 15:12:51 2014   pid: 205 uid: 502  root: no

Nov  4 15:12:51 CAS-14300 com.apple.SecurityServer[14]: Session 100008 created

Nov  4 15:12:51 CAS-14300 mds_stores[111]: (Error) SecureStore: Access token 6 changed uid from -1 to 502

Nov  4 15:12:52 CAS-14300 WindowServer[85]: **DMPROXY** (2) Found `/System/Library/CoreServices/DMProxy'.

Nov  4 15:12:52 CAS-14300 WindowServer[85]: Display 0x2b102294: Unit 0; ColorProfile { 2, "DELL G2410"}; TransferFormula (1.000000, 1.000000, 1.000000)

Nov  4 15:12:52 CAS-14300 UserEventAgent[204]: Failed to copy info dictionary for bundle /System/Library/UserEventPlugins/alfUIplugin.plugin

Nov  4 15:12:52 CAS-14300 com.apple.audio.DriverHelper[228]: The plug-in named AirPlay.driver requires extending the sandbox for the IOKit user-client class AMDRadeonX4000_AMDAccelDevice.

Nov  4 15:12:52 CAS-14300 com.apple.audio.DriverHelper[228]: The plug-in named AirPlay.driver requires extending the sandbox for the IOKit user-client class AMDRadeonX4000_AMDAccelSharedUserClient.

Nov  4 15:12:52 CAS-14300 com.apple.audio.DriverHelper[228]: The plug-in named AirPlay.driver requires extending the sandbox for the IOKit user-client class AMDSIVideoContext.

Nov  4 15:12:52 CAS-14300 com.apple.audio.DriverHelper[228]: The plug-in named AirPlay.driver requires extending the sandbox for the IOKit user-client class Gen6DVDContext.

Nov  4 15:12:52 CAS-14300 com.apple.audio.DriverHelper[228]: The plug-in named AirPlay.driver requires extending the sandbox for the IOKit user-client class IGAccelDevice.

Nov  4 15:12:52 CAS-14300 com.apple.audio.DriverHelper[228]: The plug-in named AirPlay.driver requires extending the sandbox for the IOKit user-client class IGAccelSharedUserClient.

Nov  4 15:12:52 CAS-14300 com.apple.audio.DriverHelper[228]: The plug-in named AirPlay.driver requires extending the sandbox for the IOKit user-client class IGAccelVideoContextMain.

Nov  4 15:12:52 CAS-14300 com.apple.audio.DriverHelper[228]: The plug-in named AirPlay.driver requires extending the sandbox for the IOKit user-client class IGAccelVideoContextMedia.

Nov  4 15:12:52 CAS-14300 com.apple.audio.DriverHelper[228]: The plug-in named AirPlay.driver requires extending the sandbox for the IOKit user-client class IGAccelVideoContextVEBox.

Nov  4 15:12:52 CAS-14300 com.apple.audio.DriverHelper[228]: The plug-in named AirPlay.driver requires extending the sandbox for the IOKit user-client class IOBluetoothDeviceUserClient.

Nov  4 15:12:52 CAS-14300 com.apple.audio.DriverHelper[228]: The plug-in named AirPlay.driver requires extending the sandbox for the IOKit user-client class IOHIDParamUserClient.

Nov  4 15:12:52 CAS-14300 com.apple.audio.DriverHelper[228]: The plug-in named AirPlay.driver requires extending the sandbox for the IOKit user-client class IOSurfaceRootUserClient.

Nov  4 15:12:52 CAS-14300 com.apple.audio.DriverHelper[228]: The plug-in named AirPlay.driver requires extending the sandbox for the mach service named com.apple.AirPlayXPCHelper.

Nov  4 15:12:52 CAS-14300 com.apple.audio.DriverHelper[228]: The plug-in named AirPlay.driver requires extending the sandbox for the mach service named com.apple.blued.

Nov  4 15:12:52 CAS-14300 com.apple.audio.DriverHelper[228]: The plug-in named BluetoothAudioPlugIn.driver requires extending the sandbox for the IOKit user-client class IOBluetoothDeviceUserClient.

Nov  4 15:12:52 CAS-14300 com.apple.audio.DriverHelper[228]: The plug-in named BluetoothAudioPlugIn.driver requires extending the sandbox for the mach service named com.apple.blued.

Nov  4 15:12:52 CAS-14300 com.apple.audio.DriverHelper[228]: The plug-in named BluetoothAudioPlugIn.driver requires extending the sandbox for the mach service named com.apple.bluetoothaudiod.

Nov  4 15:12:52 CAS-14300 SystemUIServer[218]: Cannot find executable for CFBundle 0x7fbd5243cc80 </System/Library/CoreServices/Menu Extras/Clock.menu> (not loaded)

Nov  4 15:12:52 CAS-14300 SystemUIServer[218]: Cannot find executable for CFBundle 0x7fbd5243ce60 </System/Library/CoreServices/Menu Extras/Volume.menu> (not loaded)

Nov  4 15:12:53 CAS-14300 com.apple.IconServicesAgent[237]: IconServicesAgent launched.

Nov  4 15:12:53 CAS-14300 sharingd[238]: Starting Up...

Nov  4 15:12:54 CAS-14300 com.apple.SecurityServer[14]: Session 100011 created

Nov  4 15:12:54 CAS-14300 Console[211]: setPresentationOptions called with NSApplicationPresentationFullScreen when there is no visible fullscreen window; this call will be ignored.

Nov  4 15:12:54 CAS-14300 accountsd[258]: assertion failed: 13F34: liblaunch.dylib + 25164 [A40A0C7B-3216-39B4-8AE0-B5D3BAF1DA8A]: 0x25

Nov  4 15:12:54 CAS-14300 com.apple.time[204]: Interval maximum value is 946100000 seconds (specified value: 9223372036854775807).

Nov  4 15:12:54 --- last message repeated 1 time ---

Nov  4 15:12:54 CAS-14300 login[260]: USER_PROCESS: 260 ttys000

Nov  4 15:12:55 CAS-14300 com.apple.launchd.peruser.502[200] (com.apple.iTunesHelper.30128[283]): Spawned and waiting for the debugger to attach before continuing...

Nov  4 15:12:55 CAS-14300 backupd[250]: Property list invalid for format: 200 (property lists cannot contain NULL)

Nov  4 15:12:56 CAS-14300 WiFiKeychainProxy[271]: [NO client logger] <Nov 10 2013 18:30:13> WIFICLOUDSYNC WiFiCloudSyncEngineCreate: created...

Nov  4 15:12:56 CAS-14300 WiFiKeychainProxy[271]: [NO client logger] <Nov 10 2013 18:30:13> WIFICLOUDSYNC WiFiCloudSyncEngineRegisterCallbacks: WiFiCloudSyncEngineCallbacks version - 0, bundle id - com.apple.wifi.WiFiKeychainProxy

Nov  4 15:12:56 CAS-14300 talagent[217]: CGSBindSurface: Invalid window 0x1e

Nov  4 15:12:56 CAS-14300 WindowServer[85]: _CGXWindowRightsRelinquish: Invalid window 0x1e

Nov  4 15:12:56 CAS-14300 talagent[217]: CGSConnectionRelinquishWindowRights(cid, result, reservedRights): CGError 1001 on line 875

Nov  4 15:12:56 CAS-14300 WindowServer[85]: _CGXTerminateWindowList: Invalid window 30

Nov  4 15:12:57 CAS-14300 secd[256]:  __EnsureFreshParameters_block_invoke_2 SOSCloudKeychainSynchronizeAndWait: The operation couldn’t be completed. (SyncedDefaults error 1025 - Remote error : No valid account for KVS)

Nov  4 15:12:57 CAS-14300 secd[256]:  __talkWithKVS_block_invoke callback error: The operation couldn’t be completed. (SyncedDefaults error 1025 - Remote error : No valid account for KVS)

Nov  4 15:12:57 CAS-14300 secd[256]:  CFPropertyListReadFromFile file file:///Users/rpurvis/Library/Keychains/6A377534-177D-5AFF-8C4F-461ADBA582E6/accountStatus.plist: The file “accountStatus.plist” couldn’t be opened because there is no such file.

Nov  4 15:12:57 CAS-14300 secd[256]:  SecErrorGetOSStatus unknown error domain: com.apple.security.sos.error for error: The operation couldn’t be completed. (com.apple.security.sos.error error 2 - Public Key not available - failed to register before call)

Nov  4 15:12:57 CAS-14300 secd[256]:  securityd_xpc_dictionary_handler WiFiKeychainProx[271] DeviceInCircle The operation couldn’t be completed. (com.apple.security.sos.error error 2 - Public Key not available - failed to register before call)

Nov  4 15:12:57 CAS-14300 imagent[247]: [Warning] Services all disappeared, removing all dependent devices

Nov  4 15:12:57 CAS-14300 imagent[247]: [Warning] Creating empty account: PlaceholderAccount for service: IMDService (iMessage)

Nov  4 15:12:57 --- last message repeated 1 time ---

Nov  4 15:12:57 CAS-14300 soagent[243]: [Warning] Services all disappeared, removing all dependent devices

Nov  4 15:12:57 CAS-14300 soagent[243]: No active accounts, killing soagent in 10 seconds

Nov  4 15:12:57 --- last message repeated 1 time ---

Nov  4 15:12:57 CAS-14300 AirPlayUIAgent[289]: 2014-11-04 03:12:57.679217 PM [AirPlayUIAgent] Changed PIN pairing: no

Nov  4 15:12:57 CAS-14300 AirPlayUIAgent[289]: 2014-11-04 03:12:57.681018 PM [AirPlayUIAgent] Changed PIN pairing: no

 

[C. R. Oldham]

Jesse,

> I have been using Salt to manage Mac clients for about a year now, and we have had this persistent issue, with 10.9 (and it is affecting 10.10 as well) Macs, that appears to be caused by the ‘salt-minion’ which causes the client to take around 5 minutes to boot. The issue seems to start after the machine is bound to my Windows AD domain. 10.8 machines do not have this issue using the same settings.

How do you install Salt on the Macs you are managing?

As a data point, I do not see this on my (admittedly small) home network of 7 macs, all Salted. I don't bind any of those machines to an AD domain though.

You mention that you

> Updated a test client with local master to the latest release of salt. no change

Which latest release? 2014.1.13 or 2014.7.0?

While I'm a long-time Mac user, I'm not sure what the following means, I'll dig into it a little. This chunk of your log seems to be where most of the delay is occurring:

--
--cro, C. R. Oldham, c...@saltstack.com

[Jesse Mcconathy]

I am using Brew to install salt on my macs.  

The version updated to was 2014.1.13

It almost seems like a DNS issue, but when I used the IP address for the master in the minion file, that should rule that out.  And I have compared the dsconfigad settings between my 10.8 and 10.9 machines and they are identical, so I can't imagine anything to change there.  Network adapter settings are all identical as well between versions.

[Thomas S Hatch]

Jesse,

How can you time these commands and tell us how long they take?

salt-call --local grains.items

salt-call grains.items

Thomas S. Hatch  |  Founder, CTO

2825 E. Cottonwood Parkway, Suite 360 | Salt Lake City, UT 84121

tha...@saltstack.com | www.saltstack.com

--
You received this message because you are subscribed to the Google Groups "Salt-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to salt-users+...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Jesse Mcconathy]

Those commands went through in just a few seconds each, on 10.9 and 10.10, with no apparent errors.

[Jesse Mcconathy]

Bumping.  Anyone have any ideas, or is anyone even using salt to manage OS X systems on a Windows AD domain?  

I am resorting to using Munki to run a script that will run the salt-minion for my clients in the interim.

[Mike Flood]

Hi,
I have no experience with OS X, but a slow boot does sound like a DNS issue to me.

Based on my experience, if DNS is not properly configured, even running 'salt-call state.show_highstate' on the minion
will take a long time. If this is the case and your boot sequence actually performs a salt-call (or if you are using the salt schedule system to run jobs - these
will start running when the minion service starts I believe), that might explain it (maybe ?-)

cheers,

[Stephen Spencer]

You also need to be careful when troubleshooting DNS issues on OSX. For better or worse, the system resolver uses a mechansim that assigns different name servers to different processes, so if you made the mistake of throwing a google name server in with your internal name server IPs, that might be the source of your problem. I guess it's an attempt to even out the load on dns servers in gigantic environments. I have... non-constructive opinions about that choice. Anyway..

Looking up the salt-master host is only the most obvious source of lookups. There may be a module that is executing a lookup and failing after a long timeout. Try removing all but one of your internal dns hosts and see if that doesn't make a difference.

Another little detail is that the common *NIX CLI utils will not help you. They are linked against a relatively typical BIND client library, so they will treat the contents of resolv.conf as you would expect.

You might also bump your minion log_level to trace and let it go through its (long) boot cycle.  That'll show each module as it's being loaded and might provide some insight.

Some swear by it. I swear at it. Best of luck!

-S

[Jesse Mcconathy]

I spent quite a bit of time looking into DNS as being the culprit and, while I could certainly have missed something, I couldn't make any change that corrected it during boot.  Primarily, using the salt-master's IP address in the minion config file, using IP addresses for the AD server, putting a static mapping the the local systems IP lookup table.  

Additionally, a manual state.highstate takes no time at all, compared to a 5 minute boot time.  As well, the minion seems to be fine on 10.8 Macs, it just started with 10.9 and has carried over to 10.10 as well.

[Jesse Mcconathy]

I did enable "ALL" logging for the minion, posted below, along with a portion of the system log which is listed first for chronographic order.

-From system log-

12/15/14 3:03:14.000 PM bootlog[0]: BOOT_TIME 1418677394 0

12/15/14 3:05:43.057 PM opendirectoryd[21]: dnssd_clientstub set_waitlimit:_daemon timed out (60 secs) without any response: Socket 8

12/15/14 3:05:46.828 PM opendirectoryd[21]: dnssd_clientstub set_waitlimit:_daemon timed out (60 secs) without any response: Socket 9

12/15/14 3:05:46.842 PM opendirectoryd[21]: dnssd_clientstub set_waitlimit:_daemon timed out (60 secs) without any response: Socket 11

-From minion logs-

2014-12-15 15:08:07,145 [salt             ][INFO    ] Setting up the Salt Minion "computer name"

2014-12-15 15:08:07,205 [salt.utils.process][DEBUG   ] Created pidfile: /var/run/salt-minion.pid

2014-12-15 15:08:07,261 [salt.config      ][DEBUG   ] Reading configuration from /etc/salt/minion

2014-12-15 15:08:07,262 [salt.loader      ][TRACE   ] loading grain in ['/var/cache/salt/minion/extmods/grains', '/usr/local/lib/python2.7/site-packages/salt/grains']

2014-12-15 15:11:20,764 [salt.loader      ][TRACE   ] Added core.append_domain to grain

Obviously, there are 3 minutes of open directory timeouts in the system log, but they disappear when I disable the minion and reboot.  Additionally the minion isn't starting (or at least isn't logging) until almost 2 and a half minutes after the final open directory timeout though, so I cannot see how they are connected.

[Benedikt Koller]

Please excuse my gravedigging on this old post, but I experience the same problem and came to the same conclusions. Did you make any progress on resolving the issue?

Best regards,

Ben

[Colton Myers]

Unfortunately we haven't had much bandwidth to work on OS X issues. That said, they're on our radar, and we hope to get to them soon.

--

Colton Myers

Core Engineer, SaltStack

@basepi on Twitter/Github/IRC

--