NetBoot Performance

[Jason]

Just starting with NetBoot and curious about what average times are. When I start NetBoot it takes about 25 minutes over 100Mb ethernet to get to Casper Imaging. My NetBoot.dmg file is 9GB (unsure if that is normal). Does this seem right? That seems like a long time to boot up.

Also, when I'm looking at server i never see any connections under NetInstall. Just says "No clients connected". Shouldn't there be something listed the moment a system starts to boot? I get BSDP Inform, BSDP ACK[LIST], and BSDP ACK [SELECT] shown in the logs.

Thanks

[bentoms]

Which OS is the NetBoot hosted on?

Also, option boot the Mac. Select the NetBoot volume & immediately hold the CMD+V keys.

It should then verbose boot, & you can have some more feedback as to what it happening.

[Jason]

It's 10.9.2 with all updates applied. I did the option boot and have a fairly large log file. Only the first part will post. I'm not sure specifically what to look for in here.

4/15/14 12:59:42.000 PM bootlog[0]  BOOT_TIME 1397581182 0
4/15/14 1:02:39.000 PM  syslogd[46] 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.
4/15/14 1:02:39.000 PM  syslogd[46] 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".
4/15/14 1:02:39.000 PM  syslogd[46] 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.
4/15/14 1:02:39.000 PM  syslogd[46] 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.
4/15/14 1:02:39.000 PM  syslogd[46] 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.
4/15/14 1:02:39.000 PM  syslogd[46] 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.
4/15/14 1:02:39.000 PM  syslogd[46] 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.
4/15/14 1:02:39.000 PM  syslogd[46] 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.
4/15/14 1:02:39.000 PM  syslogd[46] 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.
4/15/14 1:02:39.000 PM  syslogd[46] 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.
4/15/14 1:02:39.000 PM  syslogd[46] 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.
4/15/14 1:02:39.000 PM  syslogd[46] 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.
4/15/14 1:02:39.000 PM  syslogd[46] 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.
4/15/14 1:02:39.000 PM  syslogd[46] 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.
4/15/14 1:02:39.000 PM  syslogd[46] 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.
4/15/14 1:02:39.000 PM  syslogd[46] 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.
4/15/14 1:02:39.000 PM  syslogd[46] 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.
4/15/14 1:02:39.000 PM  kernel[0]   Longterm timer threshold: 1000 ms
4/15/14 1:02:39.000 PM  kernel[0]   PMAP: PCID enabled
4/15/14 1:02:39.000 PM  kernel[0]   PMAP: Supervisor Mode Execute Protection enabled
4/15/14 1:02:39.000 PM  kernel[0]   Darwin Kernel Version 13.1.0: Thu Jan 16 19:40:37 PST 2014; root:xnu-2422.90.20~2/RELEASE_X86_64
4/15/14 12:59:58.984 PM com.apple.launchd[1]    *** launchd[1] has started up. ***
4/15/14 1:02:39.000 PM  kernel[0]   vm_page_bootstrap: 4034530 free pages and 127006 wired pages
4/15/14 1:02:39.000 PM  kernel[0]   kext submap [0xffffff7f807a6000 - 0xffffff8000000000], kernel text [0xffffff8000200000 - 0xffffff80007a6000]
4/15/14 1:02:39.000 PM  kernel[0]   zone leak detection enabled
4/15/14 12:59:58.988 PM com.apple.launchd[1]    *** Verbose boot, will log to /dev/console. ***
4/15/14 1:02:39.000 PM  kernel[0]   "vm_compressor_mode" is 4
4/15/14 1:02:39.000 PM  kernel[0]   standard timeslicing quantum is 10000 us
4/15/14 1:02:39.000 PM  kernel[0]   standard background quantum is 2500 us
4/15/14 12:59:58.992 PM com.apple.launchd[1]    *** Shutdown logging is enabled. ***
4/15/14 1:02:39.000 PM  kernel[0]   mig_table_max_displ = 74
4/15/14 1:02:39.000 PM  kernel[0]   TSC Deadline Timer supported and enabled
4/15/14 1:02:39.000 PM  kernel[0]   AppleACPICPU: ProcessorId=1 LocalApicId=0 Enabled
4/15/14 1:02:39.000 PM  kernel[0]   AppleACPICPU: ProcessorId=2 LocalApicId=2 Enabled
4/15/14 1:02:39.000 PM  kernel[0]   AppleACPICPU: ProcessorId=3 LocalApicId=4 Enabled
4/15/14 1:02:39.000 PM  kernel[0]   AppleACPICPU: ProcessorId=4 LocalApicId=6 Enabled
4/15/14 1:02:39.000 PM  kernel[0]   AppleACPICPU: ProcessorId=5 LocalApicId=1 Enabled
4/15/14 1:02:39.000 PM  kernel[0]   AppleACPICPU: ProcessorId=6 LocalApicId=3 Enabled
4/15/14 1:02:39.000 PM  kernel[0]   AppleACPICPU: ProcessorId=7 LocalApicId=5 Enabled
4/15/14 1:02:39.000 PM  kernel[0]   AppleACPICPU: ProcessorId=8 LocalApicId=7 Enabled
4/15/14 1:02:39.000 PM  kernel[0]   calling mpo_policy_init for TMSafetyNet
4/15/14 1:02:39.000 PM  kernel[0]   Security policy loaded: Safety net for Time Machine (TMSafetyNet)
4/15/14 1:02:39.000 PM  kernel[0]   calling mpo_policy_init for Sandbox
4/15/14 1:02:39.000 PM  kernel[0]   Security policy loaded: Seatbelt sandbox policy (Sandbox)
4/15/14 1:02:39.000 PM  kernel[0]   calling mpo_policy_init for Quarantine
4/15/14 1:02:39.000 PM  kernel[0]   Security policy loaded: Quarantine policy (Quarantine)
4/15/14 1:02:39.000 PM  kernel[0]   Copyright (c) 1982, 1986, 1989, 1991, 1993
4/15/14 1:02:39.000 PM  kernel[0]   The Regents of the University of California. All rights reserved.
4/15/14 1:02:39.000 PM  kernel[0]   MAC Framework successfully initialized
4/15/14 1:02:39.000 PM  kernel[0]   using 16384 buffer headers and 10240 cluster IO buffer headers
4/15/14 1:02:39.000 PM  kernel[0]   AppleKeyStore starting (BUILT: Jan 16 2014 20:19:00)
4/15/14 1:02:39.000 PM  kernel[0]   IOAPIC: Version 0x20 Vectors 64:87
4/15/14 1:02:17.141 PM  hidd[70]    void __IOHIDPlugInLoadBundles(): Loaded 0 HID plugins
4/15/14 1:02:39.000 PM  kernel[0]   ACPI: sleep states S3 S4 S5
4/15/14 1:02:39.000 PM  kernel[0]   pci (build 20:00:24 Jan 16 2014), flags 0x63008, pfm64 (39 cpu) 0x7f80000000, 0x80000000
4/15/14 1:02:39.000 PM  kernel[0]   [ PCI configuration begin ]
4/15/14 1:02:39.000 PM  kernel[0]   console relocated to 0x7f80020000
4/15/14 1:02:39.000 PM  kernel[0]   [ PCI configuration end, bridges 15, devices 15 ]
4/15/14 1:02:39.000 PM  kernel[0]   AppleThunderboltNHIType2::setupPowerSavings - GPE based runtime power management
4/15/14 1:02:39.000 PM  kernel[0]   SATA WARNING: IDENTIFY DEVICE checksum not implemented.
4/15/14 1:02:39.000 PM  kernel[0]   mcache: 8 CPU(s), 64 bytes CPU cache line size
4/15/14 1:02:39.000 PM  kernel[0]   mbinit: done [128 MB total pool size, (85/42) split]
4/15/14 1:02:39.000 PM  kernel[0]   Pthread support ABORTS when sync kernel primitives misused
4/15/14 1:02:39.000 PM  kernel[0]   Waiting on <dict ID="0"><key>IOProviderClass</key><string ID="1">IONetworkInterface</string><key>IOParentMatch</key><dict ID="2"><key>IOPropertyMatch</key><dict ID="3"><key>IOMACAddress</key><data ID="4">aFs1jcIl</data></dict></dict></dict>
4/15/14 1:02:17.141 PM  hidd[70]    Posting 'com.apple.iokit.hid.displayStatus' notifyState=1
4/15/14 1:02:39.000 PM  kernel[0]   com.apple.AppleFSCompressionTypeZlib kmod start
4/15/14 1:02:39.000 PM  kernel[0]   com.apple.AppleFSCompressionTypeDataless kmod start
4/15/14 1:02:39.000 PM  kernel[0]   com.apple.AppleFSCompressionTypeZlib load succeeded
4/15/14 1:02:39.000 PM  kernel[0]   com.apple.AppleFSCompressionTypeDataless load succeeded
4/15/14 1:02:39.000 PM  kernel[0]   srom rev:11
4/15/14 1:02:39.000 PM  kernel[0]   ARPT: 1.117164: BTCOEXIST off 
4/15/14 1:02:39.000 PM  kernel[0]   ARPT: 1.118071: BRCM tunables:
4/15/14 1:02:39.000 PM  kernel[0]   ARPT: 1.118754:   pullmode[1] txringsize[  256] txsendqsize[1024] reapmin[   32] reapcount[  128]
4/15/14 1:02:39.000 PM  kernel[0]   ARPT: 1.121410: wl0: Broadcom BCM43a0, vendorID[0x14e4] BAR0[0xc1a00004]
4/15/14 1:02:39.000 PM  kernel[0]   6.30.223.154 (r420397)
4/15/14 1:02:39.000 PM  kernel[0]   USBMSC Identifier (non-unique): 000000000820 0x5ac 0x8406 0x820, 3
4/15/14 1:02:29.866 PM  fseventsd[71]   event logs in /.fseventsd out of sync with volume.  destroying old logs. (2855 154 1725733)
4/15/14 1:02:39.000 PM  kernel[0]   AppleUSBMultitouchDriver::checkStatus - received Status Packet, Payload 2: device was reinitialized
4/15/14 1:02:39.000 PM  kernel[0]   Got boot device = IOService:/AppleACPIPlatformExpert/PCI0@0/AppleACPIPCI/PEG1@1,1/IOPP/UPSB@0/IOPP/DSB1@3/IOPP/UPS0@0/IOPP/pci-bridge@0/IOPP/ethernet@0/BCM5701Enet/en0
4/15/14 1:02:39.000 PM  kernel[0]   BSD root: en0
4/15/14 1:02:39.000 PM  kernel[0]   netboot: using network interface 'en0'
4/15/14 1:02:39.000 PM  kernel[0]   netboot: retrieving IP information from DHCP response
4/15/14 1:02:39.000 PM  kernel[0]   netboot: IP address 10.20.67.123 netmask 255.255.255.0 router 10.20.67.1
4/15/14 1:02:39.000 PM  kernel[0]   netboot: adding default route 10.20.67.1
4/15/14 1:02:39.000 PM  kernel[0]   netboot: retrieving root path from BSDP response
4/15/14 1:02:39.000 PM  kernel[0]   netboot: NFS Server 10.20.153.103 Mount /Volumes/Macintosh HD2/Library/NetBoot/NetBootSP0 Image /CasperNetBoot_1092.nbi/NetBoot.dmg
4/15/14 1:02:39.000 PM  kernel[0]   Ethernet [AppleBCM5701Ethernet]: Link up on en0, 100-Megabit, Half-duplex, No flow-control, Debug [796d,0301,0de1,0300,0081,0000]
4/15/14 1:02:30.335 PM  com.apple.SecurityServer[40]    Session 100000 created
4/15/14 1:02:34.016 PM  distnoted[89]   # distnote server daemon  absolute time: 86.705399780   civil time: Tue Apr 15 13:01:07 2014   pid: 89 uid: 0  root: yes
4/15/14 1:02:39.000 PM  kernel[0]   root on 10.20.153.103:/Volumes/Macintosh HD2/Library/NetBoot/NetBootSP0
4/15/14 1:02:39.000 PM  kernel[0]   netboot_setup: calling imageboot_mount_image
4/15/14 1:02:39.000 PM  kernel[0]   IOHDIXController: NOTE: administrator is creating non-ejectable disk image
4/15/14 1:02:39.000 PM  kernel[0]   KDIFileBackingStore::_handleStart: initial R/W vn_open returned 30
4/15/14 1:02:34.783 PM  fseventsd[71]   log dir: /.fseventsd getting new uuid: 99540040-94F3-457D-B37C-6A278233DA34
4/15/14 1:02:39.000 PM  kernel[0]   imageboot_mount_image: root device 0x1000005
4/15/14 1:02:39.000 PM  kernel[0]   hfs: mounted Restore on device root_device
4/15/14 1:02:39.000 PM  kernel[0]   XCPM: registered
4/15/14 1:02:39.000 PM  kernel[0]   AppleSRP started.
4/15/14 1:02:39.000 PM  kernel[0]   hfs: set VeryLowDisk: vol:Restore, freeblks:92836, dangerlimit:111500
4/15/14 1:02:39.000 PM  kernel[0]   VM Swap Subsystem is ON
4/15/14 1:02:40.585 PM  distnoted[89]   assertion failed: 13C64: liblaunch.dylib + 25164 [38D1AB2C-A476-385F-8EA8-7AB604CA1F89]: 0x25
4/15/14 1:04:20.436 PM  xpcd[91]    Info.plist does not contain an XPCService dictionary: /System/Library/Frameworks/Security.framework/XPCServices/SecurityAgent.xpc
4/15/14 1:04:23.000 PM  kernel[0]   Waiting for DSMOS...
4/15/14 1:04:29.976 PM  com.apple.launchd[1]    (com.apple.softwareupdatecheck.initial[49]) Exited with code: 2
4/15/14 1:04:29.976 PM  xpcd[91]    Info.plist does not contain an XPCService dictionary: /System/Library/Frameworks/Security.framework/XPCServices/SecurityAgent.xpc
4/15/14 1:04:30.065 PM  NetBootClientHelper[60] primaryEthernetAddress: GetMACAddress failed (0x00000005)
4/15/14 1:04:30.296 PM  com.apple.launchd[1]    (com.apple.NetBootClientHelper[60]) Exited with code: 1
4/15/14 1:04:30.318 PM  NetBootClientHelper[100]    primaryEthernetAddress: GetMACAddress failed (0x00000005)
4/15/14 1:04:30.318 PM  com.apple.launchd[1]    (com.apple.NetBootClientHelper[100]) Exited with code: 1
4/15/14 1:04:30.318 PM  com.apple.launchd[1]    (com.apple.NetBootClientHelper) Throttling respawn: Will start in 10 seconds
4/15/14 1:04:37.754 PM  wdhelper[42]    sandbox cache error 3850
4/15/14 1:04:47.752 PM  stackshot[48]   Timed out waiting for IOKit to finish matching.
4/15/14 1:04:57.401 PM  NetBootClientHelper[102]    primaryEthernetAddress: GetMACAddress failed (0x00000005)
4/15/14 1:04:57.402 PM  com.apple.launchd[1]    (com.apple.NetBootClientHelper[102]) Exited with code: 1
4/15/14 1:05:04.858 PM  NetBootClientHelper[103]    primaryEthernetAddress: GetMACAddress failed (0x00000005)
4/15/14 1:05:04.859 PM  com.apple.launchd[1]    (com.apple.NetBootClientHelper[103]) Exited with code: 1
4/15/14 1:05:04.859 PM  com.apple.launchd[1]    (com.apple.NetBootClientHelper) Throttling respawn: Will start in 3 seconds
4/15/14 1:05:11.396 PM  NetBootClientHelper[104]    primaryEthernetAddress: GetMACAddress failed (0x00000005)
4/15/14 1:05:11.396 PM  com.apple.launchd[1]    (com.apple.NetBootClientHelper[104]) Exited with code: 1
4/15/14 1:05:11.396 PM  com.apple.launchd[1]    (com.apple.NetBootClientHelper) Throttling respawn: Will start in 7 seconds
4/15/14 1:05:16.000 PM  kernel[0]   flow_divert_kctl_disconnect (0): disconnecting group 1
4/15/14 1:05:16.683 PM  xpcd[91]    Info.plist does not contain an XPCService dictionary: /System/Library/Frameworks/Security.framework/XPCServices/SecurityAgent.xpc
4/15/14 1:05:16.818 PM  appleeventsd[79]    sandbox cache error 14: unable to open database file
4/15/14 1:05:22.691 PM  NetBootClientHelper[113]    primaryEthernetAddress: GetMACAddress failed (0x00000005)
4/15/14 1:05:22.691 PM  com.apple.launchd[1]    (com.apple.NetBootClientHelper[113]) Exited with code: 1
4/15/14 1:05:22.691 PM  com.apple.launchd[1]    (com.apple.NetBootClientHelper) Throttling respawn: Will start in 6 seconds
4/15/14 1:05:24.197 PM  configd[81] InterfaceNamer: timed out waiting for IOKit to quiesce
4/15/14 1:05:24.197 PM  configd[81] Busy services :
4/15/14 1:05:24.197 PM  configd[81]   MacBookPro11,3 [1, 342849 ms]
4/15/14 1:05:25.009 PM  NetBootClientStatus[59] dnssd_clientstub set_waitlimit:_daemon timed out (60 secs) without any response: Socket 4
4/15/14 1:05:28.000 PM  kernel[0]   IO80211Controller::dataLinkLayerAttachComplete():  adding AppleEFINVRAM notification
4/15/14 1:05:28.000 PM  kernel[0]   IO80211Interface::efiNVRAMPublished():  
4/15/14 1:05:28.827 PM  NetBootClientHelper[115]    primaryEthernetAddress: GetMACAddress failed (0x00000005)
4/15/14 1:05:28.827 PM  com.apple.launchd[1]    (com.apple.NetBootClientHelper[115]) Exited with code: 1
4/15/14 1:05:28.827 PM  com.apple.launchd[1]    (com.apple.NetBootClientHelper) Throttling respawn: Will start in 10 seconds
4/15/14 1:05:38.837 PM  NetBootClientHelper[118]    primaryEthernetAddress: GetMACAddress failed (0x00000005)
4/15/14 1:05:38.837 PM  com.apple.launchd[1]    (com.apple.NetBootClientHelper[118]) Exited with code: 1
4/15/14 1:05:38.837 PM  com.apple.launchd[1]    (com.apple.NetBootClientHelper) Throttling respawn: Will start in 10 seconds
4/15/14 1:05:48.847 PM  NetBootClientHelper[119]    primaryEthernetAddress: GetMACAddress failed (0x00000005)
4/15/14 1:05:48.847 PM  com.apple.launchd[1]    (com.apple.NetBootClientHelper[119]) Exited with code: 1
4/15/14 1:05:48.847 PM  com.apple.launchd[1]    (com.apple.NetBootClientHelper) Throttling respawn: Will start in 10 seconds
4/15/14 1:05:54.378 PM  com.apple.usbmuxd[44]   usbmuxd-327.4 on Feb 12 2014 at 14:54:33, running 64 bit
4/15/14 1:05:54.000 PM  kernel[0]   jnl: disk0s2: replay_journal: from: 5644800 to: 6251008 (joffset 0x7000)
4/15/14 1:05:54.000 PM  kernel[0]   jnl: disk0s2: journal replay done.
4/15/14 1:05:54.000 PM  kernel[0]   hfs: mounted Recovery HD on device disk0s2
4/15/14 1:05:54.951 PM  com.apple.launchd[1]    (com.apple.NetBootClientHelper) Throttling respawn: Will start in 4 seconds
4/15/14 1:05:54.951 PM  com.apple.launchd[1]    (com.apple.NetBootClientHelper) Throttling respawn: Will start in 4 seconds
4/15/14 1:05:54.951 PM  KernelEventAgent[68]    tid 54485244 type 'hfs', mounted on '/', from '/dev/disk1s2', low disk, very low disk
4/15/14 1:05:54.951 PM  KernelEventAgent[68]    tid 54485244 display_lowdisk_warning: generating verylowdisk warning for vol

[acdesigntech]

IME, 9 GB is an average .nbi size. The netboot process does not send all of that over the wire though - only the tftp components the Mac requires to netboot. The rest is on the server.

I remember my boot times being somewhere around 20 minutes over a 100Mbps connection. It does matter what OS the nbi is being hosted from. .nbis hosted on a 10.6 server seem to perform much better than the same .nbis hosted on a 10.8 server.

Does you .nbi have a RAM disk? IME that kills performance, drastically increasing boot times.

[Jason]

How can I check if it has a RAM disk?

[elislider]

I'm having issues with netboot as well.
How can I get the log file from the last CMD+V boot session? It flies past really quick and I'd like to be able to read it all carefully.