IntelMausiEthernet.kext for Intel onboard LAN

[Mieze]

Hi 

I just gave the driver a try 'cause of those big-data-transfer-problems with hnak's intel1000e.

 

Good news first: it works well, transfer speed is very good - but i got a weird problem: safari always crashes!

I rechecked it with i1000e re-installed (checked kextstat that the correct driver is loaded) no safari crash  - checked again with mausi-driver: safari crashed. Any other browser (firefox, chrome) did work...

 

I installed the driver on a yosemite 10.10.2 using "clover bootloader" on a Gigabyte H87 MB. Now I'd like to contribute to troubleshooting, but frankly I don't know how.

 

cheers

roh7

 

According to your problem description this doesn't seem to be a driver issue. There is no direct connection between the driver and the browser. Most likely the cause of the Safari crash is located somewhere else. Anyway, send me your kernel logs (see post #1 in case you don't know where to find them), maybe I find something that serves as a starting point in order to track down the issue.

 

Mieze

[StrangeNoises]

First problem today.

 

Before that, it's been great. Currently running the updated -d3 version, but running more or less since -d2 became available and it's been solid. Even transfer speeds have been more consistent - at about 90MB/s - rather than what I'd been experiencing before on hnak *and* on the unrelated Plugable USB3 interface, which is that it would hit a higher maximum, over 100MB/s, but be far more variable. I think that variability might just be local interference issues unrelated to anything else though. Just mentioning. Generally, it's been solid.

 

Today I did something different: I ran VMWare Fusion, with a Windows 7 guest. I don't do this all that often, so pretty much every time I do I have to run updates. It was the updates for the last Patch Tuesday that seemed to kill it... just downloading them from Microsoft, they never got to actually run. Until I started that going, it seemed to be happy transferring stuff across SMB to a remote (Linux/Samba) host. But with Windows Update trying to download its updates as well, the interface on the host died, as described before, only to be brought back up by a reboot or an ifconfig en0 down/up sequence.

 

I had initially been using the VMWare guest in bridge mode, but it also happened later when I tried to run Windows Update again with it in NAT mode. (I'd transferred the files I wanted to transfer via VMWare Shared Folders, which shouldn't have involved the ethernet interface(s).)

 

IPv6 is currently disabled on my network, for unrelated router reasons. So this was all on ipv4.

 

I'm primarily logging this here in case anyone else finds similar, rather than once again trying to convince people there's a problem when I appear to be the only one experiencing it ;-) If it turns out more widespread we can test deeper. It was possibly an odd edge-case involving bridge-mode networking by VMWare. And I have a likely workaround in future, in the form of perhaps *giving* the virtual machine the USB3 ethernet interface at device level for its exclusive use so it just doesn't go through the system ethernet at all.

 

Interesting perhaps that when I was having problems before on the hnak driver, if anything running VMWare seemed to have a protective effect; although by the end I'm not sure that was really consistently true. But here, the reverse seems to be true; the *only* problem I've experienced with this driver was when running VMWare. Once the guest OS was shut down, everything was solid again.

[tluck]

@strangenoises - now that you post your issues, I realized my problems (a few posts back) were in the same scenario - using Fusion 7 to run several VMware Guests. i have both windows and mac os x guests. but that common thing is VMware. i do recall switching from bridge to NAT to get internet. and then it seems after a few hours the ethernet went out. i unplugged and replugged my cable to fix ethernet. But otherwise (without VMware) no problems.

[Mieze]

@strangenoises: please send me your kernel logs.

 

Mieze

[tarasis]

Network link/stack just died without a peep from the Mausi driver, which is different than before.

 

Running Ethernet manually configured (1GB, full-duplex, MTU Standard 1500) per Mieze's suggestion. Had a iTunes library loaded over the network, Time Machine backup going, VMWare 7.1.1 running (Win 10, Bridged mode, wasn't doing anything with it), Slack, Safari, Dropbox (I had closed OwnCloud a few minutes before), SourceTree, Atom text editor. 

 

Link came back up fine after using ifconfig en0 down/up.

 

Log doesn't allude to anything. (10:55:27 appears to be when it went down)

23/02/2015 10:54:33.000 kernel[0]: Ethernet [IntelMausi]: Not enough descriptors. Stalling.
23/02/2015 10:54:33.000 kernel[0]: Ethernet [IntelMausi]: Restart stalled queue!
23/02/2015 10:54:33.000 kernel[0]: Ethernet [IntelMausi]: Not enough descriptors. Stalling.
23/02/2015 10:54:33.000 kernel[0]: Ethernet [IntelMausi]: Restart stalled queue!
23/02/2015 10:54:33.000 kernel[0]: Ethernet [IntelMausi]: Not enough descriptors. Stalling.
23/02/2015 10:54:38.470 Finder[266]: Connect Socket to file:///Users/rob/Library/Caches/SyncStateHelper/ownCloud.socket
23/02/2015 10:54:38.470 Finder[266]: Socket DISconnected!
23/02/2015 10:54:38.470 Finder[266]: ERROR: No such file or directory
23/02/2015 10:54:38.471 Finder[266]: clearFileNameCacheForPath:
23/02/2015 10:54:38.471 Finder[266]: repaintAllWindows
23/02/2015 10:54:50.468 Finder[266]: Connect Socket to file:///Users/rob/Library/Caches/SyncStateHelper/ownCloud.socket
23/02/2015 10:54:50.469 Finder[266]: Socket DISconnected!
23/02/2015 10:54:50.469 Finder[266]: ERROR: No such file or directory
23/02/2015 10:54:50.469 Finder[266]: clearFileNameCacheForPath:
23/02/2015 10:54:50.469 Finder[266]: repaintAllWindows
23/02/2015 10:54:55.470 Finder[266]: Connect Socket to file:///Users/rob/Library/Caches/SyncStateHelper/ownCloud.socket
23/02/2015 10:54:55.470 Finder[266]: Socket DISconnected!
23/02/2015 10:54:55.470 Finder[266]: ERROR: No such file or directory
23/02/2015 10:54:55.470 Finder[266]: clearFileNameCacheForPath:
23/02/2015 10:54:55.470 Finder[266]: repaintAllWindows
23/02/2015 10:55:01.886 discoveryd[52]: Basic DNSResolver UDNSServer::ProcessEvent unknown event type: 7!
23/02/2015 10:55:01.887 iTunes[1573]: Entered:_AMMuxedDeviceDisconnected, mux-device:2
23/02/2015 10:55:01.887 iTunes[1573]: Entered:__thr_AMMuxedDeviceDisconnected, mux-device:2
23/02/2015 10:55:01.887 iTunes[1573]: tid:1d4d3 - Mux ID not found in mapping dictionary
23/02/2015 10:55:01.887 iTunes[1573]: tid:1d4d3 - Can't handle disconnect with invalid ecid
23/02/2015 10:55:03.762 Finder[266]: Connect Socket to file:///Users/rob/Library/Caches/SyncStateHelper/ownCloud.socket
23/02/2015 10:55:03.763 Finder[266]: Socket DISconnected!
23/02/2015 10:55:03.763 Finder[266]: ERROR: No such file or directory
23/02/2015 10:55:03.763 Finder[266]: clearFileNameCacheForPath:
23/02/2015 10:55:03.763 Finder[266]: repaintAllWindows
23/02/2015 10:55:06.888 com.apple.usbmuxd[55]: LOCKDOWN_V2_BONJOUR_SERVICE_NAME is _apple-mobdev2._tcp,922607ea
23/02/2015 10:55:08.764 Finder[266]: Connect Socket to file:///Users/rob/Library/Caches/SyncStateHelper/ownCloud.socket
23/02/2015 10:55:08.764 Finder[266]: Socket DISconnected!
23/02/2015 10:55:08.764 Finder[266]: ERROR: No such file or directory
23/02/2015 10:55:08.764 Finder[266]: clearFileNameCacheForPath:
23/02/2015 10:55:08.764 Finder[266]: repaintAllWindows
23/02/2015 10:55:13.765 Finder[266]: Connect Socket to file:///Users/rob/Library/Caches/SyncStateHelper/ownCloud.socket
23/02/2015 10:55:13.765 Finder[266]: Socket DISconnected!
23/02/2015 10:55:13.765 Finder[266]: ERROR: No such file or directory
23/02/2015 10:55:13.765 Finder[266]: clearFileNameCacheForPath:
23/02/2015 10:55:13.765 Finder[266]: repaintAllWindows
23/02/2015 10:55:18.766 Finder[266]: Connect Socket to file:///Users/rob/Library/Caches/SyncStateHelper/ownCloud.socket
23/02/2015 10:55:18.766 Finder[266]: Socket DISconnected!
23/02/2015 10:55:18.766 Finder[266]: ERROR: No such file or directory
23/02/2015 10:55:18.766 Finder[266]: clearFileNameCacheForPath:
23/02/2015 10:55:18.766 Finder[266]: repaintAllWindows
23/02/2015 10:55:23.767 Finder[266]: Connect Socket to file:///Users/rob/Library/Caches/SyncStateHelper/ownCloud.socket
23/02/2015 10:55:23.767 Finder[266]: Socket DISconnected!
23/02/2015 10:55:23.767 Finder[266]: ERROR: No such file or directory
23/02/2015 10:55:23.767 Finder[266]: clearFileNameCacheForPath:
23/02/2015 10:55:23.767 Finder[266]: repaintAllWindows
23/02/2015 10:55:27.000 kernel[0]: ASP_TCP Disconnect: triggering reconnect by bumping reconnTrigger from curr value 0 on so 0xffffff8035bbe7b0
23/02/2015 10:55:28.000 kernel[0]: AFP_VFS afpfs_DoReconnect:  doing reconnect on /Volumes/TMBackups
23/02/2015 10:55:28.000 kernel[0]: AFP_VFS afpfs_DoReconnect:  soft mounted and hidden volume so do not notify KEA for /Volumes/TMBackups
23/02/2015 10:55:28.000 kernel[0]: AFP_VFS afpfs_DoReconnect:  Max reconnect time: 30 secs, Connect timeout: 15 secs for /Volumes/TMBackups
23/02/2015 10:55:28.000 kernel[0]: AFP_VFS afpfs_DoReconnect:  connect to the server /Volumes/TMBackups
23/02/2015 10:55:28.000 kernel[0]: ASP_TCP asp_SetTCPQoS:  sock_settclassopt got error 57 
23/02/2015 10:55:29.000 kernel[0]: ASP_TCP Disconnect: triggering reconnect by bumping reconnTrigger from curr value 0 on so 0xffffff80358643d8
23/02/2015 10:55:30.000 kernel[0]: AFP_VFS afpfs_DoReconnect:  doing reconnect on /Volumes/Drobo
23/02/2015 10:55:30.000 kernel[0]: AFP_VFS afpfs_DoReconnect:  posting to KEA EINPROGRESS for /Volumes/Drobo
23/02/2015 10:55:30.000 kernel[0]: AFP_VFS afpfs_DoReconnect:  Max reconnect time: 600 secs, Connect timeout: 15 secs for /Volumes/Drobo
23/02/2015 10:55:30.000 kernel[0]: AFP_VFS afpfs_DoReconnect:  connect to the server /Volumes/Drobo
23/02/2015 10:55:30.219 KernelEventAgent[71]: tid 54485244 received event(s) VQ_NOTRESP (1)
23/02/2015 10:55:30.219 KernelEventAgent[71]: tid 54485244 type 'afpfs', mounted on '/Volumes/Drobo', from '//tarasis@Mac%20mini._afpovertcp._tcp.local/Drobo', not responding
23/02/2015 10:55:30.220 KernelEventAgent[71]: tid 54485244 found 1 filesystem(s) with problem(s)
23/02/2015 10:55:30.222 loginwindow[69]: Error: could not load nib file for DisconnectedFS plugin
23/02/2015 10:55:34.467 Finder[266]: Connect Socket to file:///Users/rob/Library/Caches/SyncStateHelper/ownCloud.socket
23/02/2015 10:55:34.468 Finder[266]: Socket DISconnected!
23/02/2015 10:55:34.468 Finder[266]: ERROR: No such file or directory
23/02/2015 10:55:34.468 Finder[266]: clearFileNameCacheForPath:
23/02/2015 10:55:34.468 Finder[266]: repaintAllWindows
23/02/2015 10:55:43.000 kernel[0]: AFP_VFS afpfs_DoReconnect:  connect on /Volumes/TMBackups failed 60.
23/02/2015 10:55:43.000 kernel[0]: AFP_VFS afpfs_DoReconnect:  connect to the server /Volumes/TMBackups
23/02/2015 10:55:43.000 kernel[0]: ASP_TCP asp_SetTCPQoS:  sock_settclassopt got error 57 
23/02/2015 10:55:45.000 kernel[0]: AFP_VFS afpfs_DoReconnect:  connect on /Volumes/Drobo failed 60.
23/02/2015 10:55:45.000 kernel[0]: AFP_VFS afpfs_DoReconnect:  connect to the server /Volumes/Drobo
23/02/2015 10:55:45.467 Finder[266]: Connect Socket to file:///Users/rob/Library/Caches/SyncStateHelper/ownCloud.socket
23/02/2015 10:55:45.468 Finder[266]: Socket DISconnected!
23/02/2015 10:55:45.468 Finder[266]: ERROR: No such file or directory
23/02/2015 10:55:45.468 Finder[266]: clearFileNameCacheForPath:
23/02/2015 10:55:45.468 Finder[266]: repaintAllWindows
23/02/2015 10:55:50.468 Finder[266]: Connect Socket to file:///Users/rob/Library/Caches/SyncStateHelper/ownCloud.socket
23/02/2015 10:55:50.469 Finder[266]: Socket DISconnected!
23/02/2015 10:55:50.469 Finder[266]: ERROR: No such file or directory
23/02/2015 10:55:50.469 Finder[266]: clearFileNameCacheForPath:
23/02/2015 10:55:50.469 Finder[266]: repaintAllWindows
23/02/2015 10:55:55.469 Finder[266]: Connect Socket to file:///Users/rob/Library/Caches/SyncStateHelper/ownCloud.socket
23/02/2015 10:55:55.470 Finder[266]: Socket DISconnected!
23/02/2015 10:55:55.470 Finder[266]: ERROR: No such file or directory
23/02/2015 10:55:55.470 Finder[266]: clearFileNameCacheForPath:
23/02/2015 10:55:55.470 Finder[266]: repaintAllWindows
23/02/2015 10:55:58.000 kernel[0]: AFP_VFS afpfs_DoReconnect:  connect on /Volumes/TMBackups failed 60.
23/02/2015 10:55:58.000 kernel[0]: ]
23/02/2015 10:55:58.000 kernel[0]: AFP_VFS afpfs_DoReconnect:  posting to KEA to unmount /Volumes/TMBackups
23/02/2015 10:55:58.000 kernel[0]: ASP_TCP CancelOneRequest: cancelling slot 18 error 89 reqID 34416 flags 0x29 afpCmd 0x3D so 0xffffff8035bbe7b0
23/02/2015 10:55:58.000 kernel[0]: ASP_TCP CancelOneRequest: cancelling slot 19 error 89 reqID 34417 flags 0x29 afpCmd 0x3D so 0xffffff8035bbe7b0
23/02/2015 10:55:58.000 kernel[0]: ASP_TCP CancelOneRequest: cancelling slot 20 error 89 reqID 34418 flags 0x29 afpCmd 0x11 so 0xffffff8035bbe7b0
23/02/2015 10:55:58.000 kernel[0]: ASP_TCP Disconnect: triggering reconnect by bumping reconnTrigger from curr value 1 on so 0xffffff8035bbe7b0
23/02/2015 10:55:58.244 KernelEventAgent[71]: tid 54485244 received event(s) VQ_DEAD (32)
23/02/2015 10:55:58.244 KernelEventAgent[71]: tid 54485244 type 'afpfs', mounted on '/Volumes/TMBackups', from '//tarasis@Mac%20mini._afpovertcp._tcp.local./TMBackups', dead
23/02/2015 10:55:58.244 KernelEventAgent[71]: tid 54485244 force unmount //tarasis@Mac%20mini._afpovertcp._tcp.local./TMBackups from /Volumes/TMBackups
23/02/2015 10:55:58.244 KernelEventAgent[71]: tid 54485244 found 2 filesystem(s) with problem(s)
23/02/2015 10:55:58.000 kernel[0]: disk5s2: 0xc005 (UNDEFINED).
23/02/2015 10:55:58.260 com.apple.backupd[1702]: Error: (-36) SrcErr:NO Copying /Users/rob/Documents/Virtual Machines.localized/Win10 x86.vmwarevm/564d3ded-5c6f-06db-baa3-bd1303ba4ac1.vmem to /Volumes/Time Machine Backups/Backups.backupdb/MacPC/2015-02-23-105023.inProgress/E4AA567D-BFA3-443F-A516-C4EB398AFD0C/MacPC/Users/rob/Documents/Virtual Machines.localized/Win10 x86.vmwarevm
23/02/2015 10:55:58.000 kernel[0]: AFP_VFS afpfs_unmount: /Volumes/TMBackups, flags 524288, pid 71
23/02/2015 10:55:58.697 com.apple.backupd[1702]: Stopping backup.
23/02/2015 10:55:58.698 com.apple.backupd[1702]: Error: (-8062) SrcErr:NO Copying /Users/rob/Documents/Virtual Machines.localized/Win10 x86.vmwarevm/564d3ded-5c6f-06db-baa3-bd1303ba4ac1.vmem to /Volumes/Time Machine Backups/Backups.backupdb/MacPC/2015-02-23-105023.inProgress/E4AA567D-BFA3-443F-A516-C4EB398AFD0C/MacPC/Users/rob/Documents/Virtual Machines.localized/Win10 x86.vmwarevm
23/02/2015 10:55:58.700 com.apple.backupd[1702]: Copied 5720 items (4.61 GB) from volume MacPC. Linked 6015.
23/02/2015 10:55:58.701 com.apple.backupd[1702]: Copy stage failed with error:11
23/02/2015 10:55:58.000 kernel[0]: disk5s2: 0xc014 (UNDEFINED).
23/02/2015 10:55:58.710 com.apple.backupd[1702]: Backup failed with error 11: 11
23/02/2015 10:55:58.000 kernel[0]: disk5s2: 0xc014 (UNDEFINED).
23/02/2015 10:55:58.000 kernel[0]: disk5s2: 0xc014 (UNDEFINED).
23/02/2015 10:55:58.000 kernel[0]: disk5s2: 0xc014 (UNDEFINED).
23/02/2015 10:55:58.000 kernel[0]: disk5s2: 0xc014 (UNDEFINED).
23/02/2015 10:55:58.000 kernel[0]: disk5s2: 0xc014 (UNDEFINED).
23/02/2015 10:55:58.000 kernel[0]: disk5s2: 0xc014 (UNDEFINED).
23/02/2015 10:55:58.000 kernel[0]: disk5s2: 0xc014 (UNDEFINED).
23/02/2015 10:55:58.000 kernel[0]: disk5s2: 0xc014 (UNDEFINED).
23/02/2015 10:55:58.000 kernel[0]: disk5s2: 0xc014 (UNDEFINED).
23/02/2015 10:55:58.000 kernel[0]: disk5s2: 0xc014 (UNDEFINED).
23/02/2015 10:56:00.000 kernel[0]: AFP_VFS afpfs_DoReconnect:  connect on /Volumes/Drobo failed 60.
23/02/2015 10:56:00.000 kernel[0]: AFP_VFS afpfs_DoReconnect:  connect to the server /Volumes/Drobo

Going to run the same again, this time without VMWare running

 

To those who also mentioned VMWare above me, which version were you running at the time?

[StrangeNoises]

To those who also mentioned VMWare above me, which version were you running at the time?

 

7.1.1 also; the upgrade for that came down to me yesterday and I applied it before I started using it. I don't know if the same problem would also have affected the earlier 7.0.1 I had been using before that as, frankly, I hadn't been using it enough. I'm not sure it got used at all since switching to Mausi. (yes, looks like I missed 7.1.0 entirely.)

 

@mieze sorry for no logs yet; been too busy IRL, and not at that computer right now. I presume you actually mean the system.log covering the period, as there's no kernel.log as such.

[Mieze]

@strangenoises: Yes. You might also want to see post#1 for instructions where to find the kernel logs.

[StrangeNoises]

@strangenoises: Yes. You might also want to see post#1 for instructions where to find the kernel logs.

 

OK. Trawling my logs it looks like the first cocurrence was 16:23 approx on Sunday. There's *nothing* logged there from IntelMausi, but vmnet starts complaining. At 16:26 automountd reports an NFS server not responding. 16:27 I start shutting down VMWare then rebooting the computer. (It would be a couple of minutes before I remembered ifconfig down/up!)

 

After the reboot I launch VMWare again and reconfigure to NAT and transfer my files out using shared folders. Then I try the windows update again and lose the network. That happens around 16:48.

 

At 16:49:41 having shut down VMWare again, I do ifconfig en0 down, then ifconfig en0 up a few seconds later at 16:49:41. Then there's an initial problem (even though VMWare isn't running now) which I think was because of an already-running transfer happening in the Finder. Here we see IntelMausi detecting "Tx stalled?" and resetting the link itself a couple of times, to no avail (between 16:50:06 and 16:50:32), but I then cancel that transfer and do a final ifconfig down/up sequencce at 16:50:37-16:50:45 since when everything's been fine again.

 

For convenience just the Mausi bits:

spitfire:log root# zgrep IntelMausi system.log.1.gz       
Feb 22 16:29:10 localhost kernel[0]: Ethernet [IntelMausi]: TCP/IPv4 segmentation offload enabled.
Feb 22 16:29:10 localhost kernel[0]: Ethernet [IntelMausi]: TCP/IPv6 segmentation offload enabled.
Feb 22 16:29:10 localhost kernel[0]: Ethernet [IntelMausi]: TCP/IPv6 checksum offload enabled.
Feb 22 16:29:10 localhost kernel[0]: Ethernet [IntelMausi]: Version 1.0.0d3 using max interrupt rate 7000.
Feb 22 16:29:10 localhost kernel[0]: Ethernet [IntelMausi]: I217V (Rev. 5) at 0xffffff81eeba5000, d8:50:e6:4d:50:a2
Feb 22 16:29:14 spitfire kernel[0]: Ethernet [IntelMausi]: Link up on en0, 1-Gigabit, Full-duplex, Rx/Tx flow-control
Feb 22 16:49:41 spitfire kernel[0]: Ethernet [IntelMausi]: Link down on en0
Feb 22 16:49:49 spitfire kernel[0]: Ethernet [IntelMausi]: Link up on en0, 1-Gigabit, Full-duplex, Rx/Tx flow-control
Feb 22 16:50:06 spitfire kernel[0]: Ethernet [IntelMausi]: Tx stalled? Resetting chipset. txDirtyDescIndex=81, IMS=0x80020080.
Feb 22 16:50:06 spitfire kernel[0]: Ethernet [IntelMausi]: Link down on en0
Feb 22 16:50:11 spitfire kernel[0]: Ethernet [IntelMausi]: Link up on en0, 1-Gigabit, Full-duplex, Rx/Tx flow-control
Feb 22 16:50:28 spitfire kernel[0]: Ethernet [IntelMausi]: Tx stalled? Resetting chipset. txDirtyDescIndex=497, IMS=0x80020080.
Feb 22 16:50:28 spitfire kernel[0]: Ethernet [IntelMausi]: Link down on en0
Feb 22 16:50:32 spitfire kernel[0]: Ethernet [IntelMausi]: Link up on en0, 1-Gigabit, Full-duplex, Rx/Tx flow-control
Feb 22 16:50:37 spitfire kernel[0]: Ethernet [IntelMausi]: Link down on en0
Feb 22 16:50:45 spitfire kernel[0]: Ethernet [IntelMausi]: Link up on en0, 1-Gigabit, Full-duplex, Rx/Tx flow-control
spitfire:log root# 

and grep kernel for the whole period:

spitfire:log root# zgrep -e '^Feb 22 16.* kernel' system.log.1.gz
Feb 22 16:07:02 spitfire kernel[0]: DeleteIsochEP: after abort there are still 125 active TDs
Feb 22 16:07:02 spitfire kernel[0]: DeleteIsochEP: after abort there are still 107 active TDs
Feb 22 16:08:31 spitfire kernel[0]: DeleteIsochEP: after abort there are still 79 active TDs
Feb 22 16:08:31 spitfire kernel[0]: DeleteIsochEP: after abort there are still 106 active TDs
Feb 22 16:17:37 spitfire kernel[0]: hfs: mounted Recovery HD on device disk0s3
Feb 22 16:17:37 spitfire kernel[0]: hfs: unmount initiated on Recovery HD on device disk0s3
Feb 22 16:23:08 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:08 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:08 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:08 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:08 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:08 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:09 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:09 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:09 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:09 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:09 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:09 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:09 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:09 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:09 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:09 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:09 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:09 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:12 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:12 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:12 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:12 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:12 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:12 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:12 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:12 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:12 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:12 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:12 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:12 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:13 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:13 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:13 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:13 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:13 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:13 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:41 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:41 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:41 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:41 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:41 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:41 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:43 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:43 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:43 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:43 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:43 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:43 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:43 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:43 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:44 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:44 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:44 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:44 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:23:44 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:23:44 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:24:13 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:24:13 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:24:13 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:24:13 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:24:13 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:24:13 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:24:13 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:24:13 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:24:27 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:24:27 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:24:27 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:24:27 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:24:27 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:24:27 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:24:27 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:24:27 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:24:27 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:24:27 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:24:27 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:24:27 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:24:27 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:24:27 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:24:32 spitfire kernel[0]: vmnet: Failed to deep copy mbuf: 12.
Feb 22 16:24:32 spitfire kernel[0]: vmnet: mbuf_dup() failed: 12.
Feb 22 16:27:02 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port userListener0.
Feb 22 16:27:02 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port userif6.
Feb 22 16:27:02 spitfire kernel[0]: en0: promiscuous mode disable succeeded
Feb 22 16:27:02 spitfire kernel[0]: vmnet: bridge-en0: disabled promiscuous mode
Feb 22 16:27:02 spitfire kernel[0]: vmnet: VNetUserIfFree: freeing userif6.
Feb 22 16:27:04 spitfire kernel[0]: vmmon: Cleaned up 774902 virtual main memory pages from VM.
Feb 22 16:27:04 spitfire kernel[0]: vmmon: Cleaned up 5734 monitor anonymous pages from VM.
Feb 22 16:27:04 spitfire kernel[0]: vmmon: Cleaned up 3580 user anonymous pages from VM.
Feb 22 16:27:06 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port userif2.
Feb 22 16:27:06 spitfire kernel[0]: vmnet: VNetUserIfFree: freeing userif2.
Feb 22 16:27:07 spitfire kernel[0]: vmnet: netif-vmnet1: SIOCSIFFLAGS: 0x8862
Feb 22 16:27:07 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port netif0.
Feb 22 16:27:07 spitfire kernel[0]: vmnet: netif-vmnet1: SIOCPROTODETACH failed: 16.
Feb 22 16:27:07 spitfire kernel[0]: vmnet: netif-vmnet1: Deleting protocol 2.
Feb 22 16:27:07 spitfire kernel[0]: vmnet: netif-vmnet1: Detaching...
Feb 22 16:27:07 spitfire kernel[0]: vmnet: netif-vmnet1: Detached.
Feb 22 16:27:07 spitfire kernel[0]: vmnet: Freeing hub b4904f.
Feb 22 16:27:07 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port userif5.
Feb 22 16:27:07 spitfire kernel[0]: vmnet: VNetUserIfFree: freeing userif5.
Feb 22 16:27:07 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port userif3.
Feb 22 16:27:07 spitfire kernel[0]: vmnet: VNetUserIfFree: freeing userif3.
Feb 22 16:27:07 spitfire kernel[0]: vmnet: netif-vmnet8: SIOCSIFFLAGS: 0x8862
Feb 22 16:27:07 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port netif1.
Feb 22 16:27:07 spitfire kernel[0]: vmnet: netif-vmnet8: SIOCPROTODETACH failed: 16.
Feb 22 16:27:07 spitfire kernel[0]: vmnet: netif-vmnet8: Deleting protocol 2.
Feb 22 16:27:07 spitfire kernel[0]: vmnet: netif-vmnet8: Detaching...
Feb 22 16:27:07 spitfire kernel[0]: vmnet: netif-vmnet8: Detached.
Feb 22 16:27:07 spitfire kernel[0]: vmnet: Freeing hub 971a04f.
Feb 22 16:27:07 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port bridge0.
Feb 22 16:27:07 spitfire kernel[0]: vmnet: bridge-en0: filter detached
Feb 22 16:27:07 spitfire kernel[0]: vmnet: bridge-en0: down
Feb 22 16:27:07 spitfire kernel[0]: vmnet: bridge-en0: detached
Feb 22 16:27:07 spitfire kernel[0]: vmnet: Freeing hub 10a9804f.
Feb 22 16:27:07 spitfire kernel[0]: vmmon: Removing module.
Feb 22 16:27:07 spitfire kernel[0]: vmmon: Timer thread stopping...
Feb 22 16:27:07 spitfire kernel[0]: vmmon: Timer thread stopped.
Feb 22 16:27:07 spitfire kernel[0]: vmmon: Module removed.
Feb 22 16:27:07 spitfire kernel[0]: vmnet: Removing module.
Feb 22 16:27:07 spitfire kernel[0]: vmnet: Module removed.
Feb 22 16:27:07 spitfire kernel[0]: vsock: Removing module.
Feb 22 16:27:07 spitfire kernel[0]: vsock: End workloop.
Feb 22 16:27:07 spitfire kernel[0]: vsock: Module removed.
Feb 22 16:27:07 spitfire kernel[0]: vmci: Removing module.
Feb 22 16:27:07 spitfire kernel[0]: vmci: End helper queue thread.
Feb 22 16:27:07 spitfire kernel[0]: vmci: Module removed.
Feb 22 16:27:22 spitfire kernel[0]: Kext loading now disabled.
Feb 22 16:27:22 spitfire kernel[0]: Kext unloading now disabled.
Feb 22 16:27:22 spitfire kernel[0]: Kext autounloading now disabled.
Feb 22 16:27:22 spitfire kernel[0]: Kernel requests now disabled.
Feb 22 16:29:10 localhost kernel[0]: Longterm timer threshold: 1000 ms
Feb 22 16:29:10 localhost kernel[0]: PMAP: PCID enabled
Feb 22 16:29:10 localhost kernel[0]: PMAP: Supervisor Mode Execute Protection enabled
Feb 22 16:29:10 localhost kernel[0]: Darwin Kernel Version 14.1.0: Mon Dec 22 23:10:38 PST 2014; root:xnu-2782.10.72~2/RELEASE_X86_64
Feb 22 16:29:10 localhost kernel[0]: vm_page_bootstrap: 4020495 free pages and 141041 wired pages
Feb 22 16:29:10 localhost kernel[0]: kext submap [0xffffff7f80a00000 - 0xffffff8000000000], kernel text [0xffffff8000200000 - 0xffffff8000a00000]
Feb 22 16:29:10 localhost kernel[0]: zone leak detection enabled
Feb 22 16:29:10 localhost kernel[0]: "vm_compressor_mode" is 4
Feb 22 16:29:10 localhost kernel[0]: multiq scheduler config: deep-drain 0, urgent first 1, depth limit 4, band limit 127, sanity check 0
Feb 22 16:29:10 localhost kernel[0]: standard timeslicing quantum is 10000 us
Feb 22 16:29:10 localhost kernel[0]: standard background quantum is 2500 us
Feb 22 16:29:10 localhost kernel[0]: mig_table_max_displ = 13
Feb 22 16:29:10 localhost kernel[0]: TSC Deadline Timer supported and enabled
Feb 22 16:29:10 localhost kernel[0]: AppleACPICPU: ProcessorId=1 LocalApicId=0 Enabled
Feb 22 16:29:10 localhost kernel[0]: AppleACPICPU: ProcessorId=2 LocalApicId=2 Enabled
Feb 22 16:29:10 localhost kernel[0]: AppleACPICPU: ProcessorId=3 LocalApicId=4 Enabled
Feb 22 16:29:10 localhost kernel[0]: AppleACPICPU: ProcessorId=4 LocalApicId=6 Enabled
Feb 22 16:29:10 localhost kernel[0]: AppleACPICPU: ProcessorId=5 LocalApicId=1 Enabled
Feb 22 16:29:10 localhost kernel[0]: AppleACPICPU: ProcessorId=6 LocalApicId=3 Enabled
Feb 22 16:29:10 localhost kernel[0]: AppleACPICPU: ProcessorId=7 LocalApicId=5 Enabled
Feb 22 16:29:10 localhost kernel[0]: AppleACPICPU: ProcessorId=8 LocalApicId=7 Enabled
Feb 22 16:29:10 localhost kernel[0]: calling mpo_policy_init for TMSafetyNet
Feb 22 16:29:10 localhost kernel[0]: Security policy loaded: Safety net for Time Machine (TMSafetyNet)
Feb 22 16:29:10 localhost kernel[0]: calling mpo_policy_init for AMFI
Feb 22 16:29:10 localhost kernel[0]: Security policy loaded: Apple Mobile File Integrity (AMFI)
Feb 22 16:29:10 localhost kernel[0]: calling mpo_policy_init for Sandbox
Feb 22 16:29:10 localhost kernel[0]: Security policy loaded: Seatbelt sandbox policy (Sandbox)
Feb 22 16:29:10 localhost kernel[0]: calling mpo_policy_init for Quarantine
Feb 22 16:29:10 localhost kernel[0]: Security policy loaded: Quarantine policy (Quarantine)
Feb 22 16:29:10 localhost kernel[0]: Copyright (c) 1982, 1986, 1989, 1991, 1993
Feb 22 16:29:10 localhost kernel[0]: The Regents of the University of California. All rights reserved.
Feb 22 16:29:10 localhost kernel[0]: MAC Framework successfully initialized
Feb 22 16:29:10 localhost kernel[0]: using 16384 buffer headers and 10240 cluster IO buffer headers
Feb 22 16:29:10 localhost kernel[0]: FakeSMCKeyStore: started
Feb 22 16:29:10 localhost kernel[0]: AppleKeyStore starting (BUILT: Dec 22 2014 23:20:35)
Feb 22 16:29:10 localhost kernel[0]: IOAPIC: Version 0x20 Vectors 64:87
Feb 22 16:29:10 localhost kernel[0]: ACPI: sleep states S3 S4 S5
Feb 22 16:29:10 localhost kernel[0]: CPUSensors: CPU family 0x6, model 0x3c, stepping 0x3, cores 4, threads 8, TJmax 100
Feb 22 16:29:10 localhost kernel[0]: CPUSensors: setting platform keys to [j43     ]
Feb 22 16:29:10 localhost kernel[0]: CPUSensors: base CPU multiplier is 35
Feb 22 16:29:10 localhost kernel[0]: CPUSensors: started
Feb 22 16:29:10 localhost kernel[0]: pci (build 23:16:47 Dec 22 2014), flags 0xe3000, pfm64 (39 cpu) 0x7f80000000, 0x80000000
Feb 22 16:29:10 localhost kernel[0]: [ PCI configuration begin ]
Feb 22 16:29:10 localhost kernel[0]: ACPISensors (TZ00): 1 sensor added
Feb 22 16:29:10 localhost kernel[0]: ACPISensors (TZ00): started
Feb 22 16:29:10 localhost kernel[0]: ACPISensors (TZ01): 1 sensor added
Feb 22 16:29:10 localhost kernel[0]: ACPISensors (TZ01): started
Feb 22 16:29:10 localhost kernel[0]: FakeSMC v6.0.1426 Copyright 2014 netkas, slice, usr-sse2, kozlek, navi, THe KiNG, RehabMan. All rights reserved.
Feb 22 16:29:10 localhost kernel[0]: FakeSMC: 13 preconfigured keys added
Feb 22 16:29:10 localhost kernel[0]: FakeSMC: 5 keys exported by Clover EFI
Feb 22 16:29:10 localhost kernel[0]: SMC: successfully initialized
Feb 22 16:29:10 localhost kernel[0]: console relocated to 0x7f80000000
Feb 22 16:29:10 localhost kernel[0]: [ PCI configuration end, bridges 4, devices 15 ]
Feb 22 16:29:10 localhost kernel[0]: mcache: 8 CPU(s), 64 bytes CPU cache line size
Feb 22 16:29:10 localhost kernel[0]: mbinit: done [128 MB total pool size, (85/42) split]
Feb 22 16:29:10 localhost kernel[0]: rooting via boot-uuid from /chosen: A91E262B-92CC-3D8C-9894-77A1E8DD9D0F
Feb 22 16:29:10 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>
Feb 22 16:29:10 localhost kernel[0]: com.apple.AppleFSCompressionTypeZlib kmod start
Feb 22 16:29:10 localhost kernel[0]: com.apple.AppleFSCompressionTypeDataless kmod start
Feb 22 16:29:10 localhost kernel[0]: com.apple.AppleFSCompressionTypeZlib load succeeded
Feb 22 16:29:10 localhost kernel[0]: com.apple.AppleFSCompressionTypeDataless load succeeded
Feb 22 16:29:10 localhost kernel[0]: Ethernet [IntelMausi]: TCP/IPv4 segmentation offload enabled.
Feb 22 16:29:10 localhost kernel[0]: Ethernet [IntelMausi]: TCP/IPv6 segmentation offload enabled.
Feb 22 16:29:10 localhost kernel[0]: Ethernet [IntelMausi]: TCP/IPv6 checksum offload enabled.
Feb 22 16:29:10 localhost kernel[0]: Ethernet [IntelMausi]: Version 1.0.0d3 using max interrupt rate 7000.
Feb 22 16:29:10 localhost kernel[0]: Got boot device = IOService:/AppleACPIPlatformExpert/PCI0@0/AppleACPIPCI/SAT0@1F,2/AppleIntelPchSeriesAHCI/PRT0@0/IOAHCIDevice@0/AppleAHCIDiskDriver/IOAHCIBlockStorageDevice/IOBlockStorageDriver/INTEL SSDSC2BW120A4 Media/IOGUIDPartitionScheme/Macintosh HD@2
Feb 22 16:29:10 localhost kernel[0]: BSD root: disk0s2, major 1, minor 2
Feb 22 16:29:10 localhost kernel[0]: USBF:    0.726    GenericUSBXHCI::CreateRootHubDevice  Bus 14 already taken
Feb 22 16:29:10 localhost kernel[0]: hfs: mounted Macintosh HD on device root_device
Feb 22 16:29:10 localhost kernel[0]: XCPM: registered
Feb 22 16:29:10 localhost kernel[0]: VM Swap Subsystem is ON
Feb 22 16:29:10 localhost kernel[0]: Ethernet [IntelMausi]: I217V (Rev. 5) at 0xffffff81eeba5000, d8:50:e6:4d:50:a2
Feb 22 16:29:10 localhost kernel[0]: USBMSC Identifier (non-unique): ㅓ㘶夶䙋あ〰䝁†ँ ਁఀ䑆C䑓 0xe8d 0x1956 0x0, 2
Feb 22 16:29:10 localhost kernel[0]: USBMSC Identifier (non-unique): 575834314132345939363834 0x1058 0x820 0x1007, 3
Feb 22 16:29:10 localhost kernel[0]: IOGraphics flags 0x43
Feb 22 16:29:10 localhost kernel[0]: Previous shutdown cause: 5
Feb 22 16:29:10 localhost kernel[0]: DSMOS has arrived
Feb 22 16:29:10 localhost kernel[0]: [IOBluetoothHCIController][start] -- completed
Feb 22 16:29:10 localhost kernel[0]: hmm.. mismatch sizes: 3100 vs 20
Feb 22 16:29:10 localhost kernel[0]: PPGTT is enabled
Feb 22 16:29:10 localhost kernel[0]: hfs: mounted Greens on device disk7
Feb 22 16:29:10 localhost kernel[0]: IOPPF: XCPM mode
Feb 22 16:29:10 localhost kernel[0]: [AGPM Controller] unknownPlatform
Feb 22 16:29:10 localhost kernel[0]: X86PlatformShim::sendPStates - Success!
Feb 22 16:29:11 localhost kernel[0]: USB Sound assertion in AppleUSBAudioDevice at line 2381
Feb 22 16:29:11 localhost kernel[0]: hfs: mounted Sams on device disk6
Feb 22 16:29:11 localhost kernel[0]: USB Sound assertion in AppleUSBAudioDevice at line 2381
Feb 22 16:29:11 localhost kernel[0]: [AGPM Controller] unknownPlatform
Feb 22 16:29:11 localhost kernel[0]: X86PlatformPlugin::cgRegisterCallbackHandler - gpu internal PLimit notification already registered
Feb 22 16:29:11 localhost kernel[0]: ** GPU Hardware VM is enabled (multispace: enabled, page table updates with DMA: enabled)
Feb 22 16:29:11 spitfire kernel[0]: **** [IOBluetoothHostControllerUSBTransport][start] -- completed -- result = TRUE -- 0xb000 ****
Feb 22 16:29:11 spitfire kernel[0]: **** [BroadcomBluetoothHostControllerUSBTransport][start] -- Completed (matched on Device) -- 0xb000 ****
Feb 22 16:29:11 spitfire kernel[0]: [IOBluetoothHCIController][staticBluetoothTransportShowsUp] -- Received Bluetooth Controller register service notification -- 0xb000 
Feb 22 16:29:11 spitfire kernel[0]: [IOBluetoothHCIController::setConfigState] calling registerService
Feb 22 16:29:11 spitfire kernel[0]: **** [IOBluetoothHCIController][ProcessBluetoothTransportShowsUpActionWL] -- Connected to the transport successfully -- 0xc980 -- 0x7800 -- 0xb000 ****
Feb 22 16:29:11 spitfire kernel[0]: USB Sound assertion in AppleUSBAudioDevice at line 2381
Feb 22 16:29:11 spitfire kernel[0]: USBMSC Identifier (non-unique): 000000264001 0x424 0x4063 0x191, 2
Feb 22 16:29:13 spitfire kernel[0]: hfs: mounted BlueBox on device disk8s2
Feb 22 16:29:13 spitfire kernel[0]: hfs: unmount initiated on BlueBox on device disk8s2
Feb 22 16:29:13 spitfire kernel[0]: IOBluetoothDevice::setProperties() -- calling hciController->CallCreateDeviceReporter() -- this = 0x7c00 
Feb 22 16:29:13 spitfire kernel[0]: IOBluetoothHCIController::CallCreateDeviceReporter -- calling enqueueAction() -- device = 0x7c00 
Feb 22 16:29:13 spitfire kernel[0]: IOBluetoothHCIController::CreateDeviceReporterAction -- device = = 0x7c00 
Feb 22 16:29:13 spitfire kernel[0]: IOBluetoothHCIController::CreateDeviceReporterAction -- calling CreateDeviceReporter() device = = 0x7c00 
Feb 22 16:29:13 spitfire kernel[0]: IOBluetoothHCIController::CreateDeviceReporter -- device = = 0x7c00 
Feb 22 16:29:13 spitfire kernel[0]: [BNBTrackpadDevice::init][85.3] init is complete
Feb 22 16:29:14 spitfire kernel[0]: Ethernet [IntelMausi]: Link up on en0, 1-Gigabit, Full-duplex, Rx/Tx flow-control
Feb 22 16:29:14 spitfire kernel[0]: [BNBTrackpadDevice::handleStart][85.3] returning 1
Feb 22 16:29:14 spitfire kernel[0]: [AppleMultitouchHIDEventDriver::start] entered
Feb 22 16:29:14 spitfire kernel[0]: [AppleMultitouchDevice::start] entered
Feb 22 16:29:31 spitfire kernel[0]: BUG in process suhelperd[283]: over-released legacy external boost assertions (1 total, 1 external, 0 legacy-external)
Feb 22 16:29:31 spitfire kernel[0]: BUG in process suhelperd[283]: over-released legacy external boost assertions (1 total, 1 external, 0 legacy-external)
Feb 22 16:29:31 spitfire kernel[0]: BUG in process suhelperd[283]: over-released legacy external boost assertions (1 total, 1 external, 0 legacy-external)
Feb 22 16:29:37 spitfire kernel[0]: AppleKeyStore:Sending lock change 0 for handle -501
Feb 22 16:29:37 spitfire kernel[0]: hfs: mounted BlueBox on device disk8s2
Feb 22 16:29:39 spitfire kernel[0]: Sandbox: appleeventsd(24) deny file-read-metadata /Library
Feb 22 16:29:39 spitfire kernel[0]: Sandbox: appleeventsd(24) deny mach-lookup com.apple.ocspd
Feb 22 16:29:43 spitfire kernel[0]: vmci: Loaded com.vmware.kext.vmci Version 90.6.3 Build 2498930 (Feb  7 2015 15:34:52)
Feb 22 16:29:43 spitfire kernel[0]: vmci: VMCI: shared components initialized.
Feb 22 16:29:43 spitfire kernel[0]: vmci: VMCI: host components initialized.
Feb 22 16:29:43 spitfire kernel[0]: vmci: Module initialized.
Feb 22 16:29:43 spitfire kernel[0]: vmci: Begin helper queue thread.
Feb 22 16:29:43 spitfire kernel[0]: vsock: Loaded com.vmware.kext.vsockets Version 90.6.0 Build 2498930 (Feb  7 2015 15:34:57)
Feb 22 16:29:43 spitfire kernel[0]: vsock: Begin workloop.
Feb 22 16:29:43 spitfire kernel[0]: vsock: Module initialized.
Feb 22 16:29:43 spitfire kernel[0]: vmnet: Loaded com.vmware.kext.vmnet Version 0249.89.30 Build 2498930 (Feb  7 2015 15:35:03)
Feb 22 16:29:43 spitfire kernel[0]: vmnet: Module initialized.
Feb 22 16:29:43 spitfire kernel[0]: vmmon: Loaded com.vmware.kext.vmx86 Version 0249.89.30 Build 2498930 (Feb  7 2015 15:34:42)
Feb 22 16:29:43 spitfire kernel[0]: vmmon: Cycles 88
Feb 22 16:29:43 spitfire kernel[0]: vmmon: Timer thread started.
Feb 22 16:29:43 spitfire kernel[0]: vmmon: Module initialized.
Feb 22 16:29:43 spitfire kernel[0]: vmnet: VNetUserIf_Create: created userif0.
Feb 22 16:29:43 spitfire kernel[0]: vmnet: VMNetConnect: returning port userif0.
Feb 22 16:29:43 spitfire kernel[0]: vmnet: Allocated hub ffffffffffe8a5df for hubNum 0.
Feb 22 16:29:43 spitfire kernel[0]: vmnet: VMNET_SO_BINDTOHUB: port: paddr 00:50:56:e7:19:46
Feb 22 16:29:43 spitfire kernel[0]: vmnet: Hub 0
Feb 22 16:29:43 spitfire kernel[0]: vmnet: 	Port 0
Feb 22 16:29:43 spitfire kernel[0]: vmnet: bridge-en0: media 20 devName en family 2
Feb 22 16:29:43 spitfire kernel[0]: vmnet: bridge-en0: up
Feb 22 16:29:43 spitfire kernel[0]: vmnet: bridge-en0: attached
Feb 22 16:29:43 spitfire kernel[0]: vmnet: VNetUserIfFree: freeing userif0.
Feb 22 16:29:44 spitfire kernel[0]: vmnet: VNetUserIf_Create: created userif1.
Feb 22 16:29:44 spitfire kernel[0]: vmnet: VMNetConnect: returning port userif1.
Feb 22 16:29:44 spitfire kernel[0]: vmnet: Allocated hub ffffffffffe755df for hubNum 1.
Feb 22 16:29:44 spitfire kernel[0]: vmnet: VMNET_SO_BINDTOHUB: port: paddr 00:50:56:e5:a6:c4
Feb 22 16:29:44 spitfire kernel[0]: vmnet: Hub 1
Feb 22 16:29:44 spitfire kernel[0]: vmnet: 	Port 0
Feb 22 16:29:44 spitfire kernel[0]: vmnet: VNetUserIfFree: freeing userif1.
Feb 22 16:29:44 spitfire kernel[0]: vmnet: netif-vmnet1: Adding protocol 2.
Feb 22 16:29:44 spitfire kernel[0]: vmnet: netif-vmnet1: SIOCSIFFLAGS: 0x8863
Feb 22 16:29:44 spitfire kernel[0]: vmnet: bridge-en0: interface en is coming UP
Feb 22 16:29:44 spitfire kernel[0]: vmnet: VNetUserIf_Create: created userif2.
Feb 22 16:29:44 spitfire kernel[0]: vmnet: VMNetConnect: returning port userif2.
Feb 22 16:29:44 spitfire kernel[0]: vmnet: VMNET_SO_BINDTOHUB: port: paddr 00:50:56:fe:7e:f1
Feb 22 16:29:44 spitfire kernel[0]: vmnet: Hub 1
Feb 22 16:29:44 spitfire kernel[0]: vmnet: 	Port 0
Feb 22 16:29:44 spitfire kernel[0]: vmnet: 	Port 1
Feb 22 16:29:44 spitfire kernel[0]: vmnet: VNetUserIf_Create: created userif3.
Feb 22 16:29:44 spitfire kernel[0]: vmnet: VMNetConnect: returning port userif3.
Feb 22 16:29:44 spitfire kernel[0]: vmnet: Allocated hub ffffffffffe5e5df for hubNum 8.
Feb 22 16:29:44 spitfire kernel[0]: vmnet: VMNET_SO_BINDTOHUB: port: paddr 00:50:56:f5:77:7f
Feb 22 16:29:44 spitfire kernel[0]: vmnet: Hub 8
Feb 22 16:29:44 spitfire kernel[0]: vmnet: 	Port 0
Feb 22 16:29:44 spitfire kernel[0]: vmnet: VMNetSetopt: Set link state UP
Feb 22 16:29:44 spitfire kernel[0]: vmnet: VNetUserIf_Create: created userif4.
Feb 22 16:29:44 spitfire kernel[0]: vmnet: VMNetConnect: returning port userif4.
Feb 22 16:29:44 spitfire kernel[0]: vmnet: VMNET_SO_BINDTOHUB: port: paddr 00:50:56:fb:10:8a
Feb 22 16:29:44 spitfire kernel[0]: vmnet: Hub 8
Feb 22 16:29:44 spitfire kernel[0]: vmnet: 	Port 0
Feb 22 16:29:44 spitfire kernel[0]: vmnet: 	Port 1
Feb 22 16:29:44 spitfire kernel[0]: vmnet: VNetUserIfFree: freeing userif4.
Feb 22 16:29:44 spitfire kernel[0]: vmnet: netif-vmnet8: Adding protocol 2.
Feb 22 16:29:44 spitfire kernel[0]: vmnet: netif-vmnet8: SIOCSIFFLAGS: 0x8863
Feb 22 16:29:44 spitfire kernel[0]: vmnet: VNetUserIf_Create: created userif5.
Feb 22 16:29:44 spitfire kernel[0]: vmnet: VMNetConnect: returning port userif5.
Feb 22 16:29:44 spitfire kernel[0]: vmnet: VMNET_SO_BINDTOHUB: port: paddr 00:50:56:f0:d5:f7
Feb 22 16:29:44 spitfire kernel[0]: vmnet: Hub 8
Feb 22 16:29:44 spitfire kernel[0]: vmnet: 	Port 0
Feb 22 16:29:44 spitfire kernel[0]: vmnet: 	Port 1
Feb 22 16:29:44 spitfire kernel[0]: vmnet: 	Port 2
Feb 22 16:29:44 spitfire kernel[0]: fsevents: watcher dbfseventsd (pid: 519) - Using /dev/fsevents directly is unsupported.  Migrate to FSEventsFramework
Feb 22 16:29:44 spitfire kernel[0]: vmioplug: Loaded com.vmware.kext.vmioplug.14.1.3 Version 14.1.3 Build 2498930 (Feb  7 2015 15:35:06)
Feb 22 16:29:45 spitfire kernel[0]: vmmon: offset 0: 80
Feb 22 16:29:45 spitfire kernel[0]: vmmon: offset 1: 16
Feb 22 16:29:45 spitfire kernel[0]: vmmon: offset 2: 56
Feb 22 16:29:45 spitfire kernel[0]: vmmon: offset 3: 64
Feb 22 16:29:45 spitfire kernel[0]: vmmon: offset 4: 76
Feb 22 16:29:45 spitfire kernel[0]: vmmon: PTSC: initialized at 3497374000 Hz using reference clock, TSCs are synchronized.
Feb 22 16:29:45 spitfire kernel[0]: vmmon: Cycles 60
Feb 22 16:29:45 spitfire kernel[0]: vmnet: VNetUserIf_Create: created userif6.
Feb 22 16:29:45 spitfire kernel[0]: vmnet: VMNetConnect: returning port userif6.
Feb 22 16:29:45 spitfire kernel[0]: en0: promiscuous mode enable succeeded
Feb 22 16:29:45 spitfire kernel[0]: vmnet: bridge-en0: enabled promiscuous mode
Feb 22 16:29:45 spitfire kernel[0]: vmnet: VMNET_SO_BINDTOHUB: port: paddr 00:50:56:e3:a3:4b
Feb 22 16:29:45 spitfire kernel[0]: vmnet: Hub 0
Feb 22 16:29:45 spitfire kernel[0]: vmnet: 	Port 0
Feb 22 16:29:45 spitfire kernel[0]: vmnet: 	Port 1
Feb 22 16:29:45 spitfire kernel[0]: vmnet: VNetUserIf_Create: created userif7.
Feb 22 16:29:45 spitfire kernel[0]: vmnet: VMNetConnect: returning port userif7.
Feb 22 16:29:45 spitfire kernel[0]: vmnet: VMNET_SO_BINDTOHUB: port: paddr 00:50:56:e6:ae:b2
Feb 22 16:29:45 spitfire kernel[0]: vmnet: Hub 0
Feb 22 16:29:45 spitfire kernel[0]: vmnet: 	Port 0
Feb 22 16:29:45 spitfire kernel[0]: vmnet: 	Port 1
Feb 22 16:29:45 spitfire kernel[0]: vmnet: 	Port 2
Feb 22 16:29:45 spitfire kernel[0]: vmnet: VNetUserIfFree: freeing userif7.
Feb 22 16:29:49 spitfire kernel[0]: BUG in process suhelperd[283]: over-released legacy external boost assertions (0 total, 0 external, 0 legacy-external)
Feb 22 16:29:54 spitfire kernel[0]: Sandbox: appleeventsd(24) deny file-read-metadata /Library
Feb 22 16:29:54 spitfire kernel[0]: Sandbox: appleeventsd(24) deny mach-lookup com.apple.ocspd
Feb 22 16:29:59 spitfire kernel[0]: USB Sound assertion in AppleUSBAudioEngine at line 1616
Feb 22 16:30:53 spitfire kernel[0]: process vmware-vmx[538] caught causing excessive wakeups. Observed wakeups rate (per sec): 656; Maximum permitted wakeups rate (per sec): 150; Observation period: 300 seconds; Task lifetime number of wakeups: 45026
Feb 22 16:31:20 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port userListener0.
Feb 22 16:31:20 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port userif6.
Feb 22 16:31:20 spitfire kernel[0]: en0: promiscuous mode disable succeeded
Feb 22 16:31:20 spitfire kernel[0]: vmnet: bridge-en0: disabled promiscuous mode
Feb 22 16:31:20 spitfire kernel[0]: vmnet: VNetUserIfFree: freeing userif6.
Feb 22 16:31:26 spitfire kernel[0]: vmnet: VNetUserIf_Create: created userif8.
Feb 22 16:31:26 spitfire kernel[0]: vmnet: VMNetConnect: returning port userif8.
Feb 22 16:31:26 spitfire kernel[0]: vmnet: VMNET_SO_BINDTOHUB: port: paddr 00:50:56:f6:f1:5e
Feb 22 16:31:26 spitfire kernel[0]: vmnet: Hub 8
Feb 22 16:31:26 spitfire kernel[0]: vmnet: 	Port 0
Feb 22 16:31:26 spitfire kernel[0]: vmnet: 	Port 1
Feb 22 16:31:26 spitfire kernel[0]: vmnet: 	Port 2
Feb 22 16:31:26 spitfire kernel[0]: vmnet: 	Port 3
Feb 22 16:31:26 spitfire kernel[0]: vmnet: VNetUserIf_Create: created userif9.
Feb 22 16:31:26 spitfire kernel[0]: vmnet: VMNetConnect: returning port userif9.
Feb 22 16:31:26 spitfire kernel[0]: vmnet: VMNET_SO_BINDTOHUB: port: paddr 00:50:56:f9:11:5f
Feb 22 16:31:26 spitfire kernel[0]: vmnet: Hub 8
Feb 22 16:31:26 spitfire kernel[0]: vmnet: 	Port 0
Feb 22 16:31:26 spitfire kernel[0]: vmnet: 	Port 1
Feb 22 16:31:26 spitfire kernel[0]: vmnet: 	Port 2
Feb 22 16:31:26 spitfire kernel[0]: vmnet: 	Port 3
Feb 22 16:31:26 spitfire kernel[0]: vmnet: 	Port 4
Feb 22 16:31:26 spitfire kernel[0]: vmnet: VNetUserIfFree: freeing userif9.
Feb 22 16:31:31 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port userListener1.
Feb 22 16:31:31 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port userif8.
Feb 22 16:31:31 spitfire kernel[0]: vmnet: VNetUserIfFree: freeing userif8.
Feb 22 16:31:31 spitfire kernel[0]: vmnet: VNetUserIf_Create: created userif10.
Feb 22 16:31:31 spitfire kernel[0]: vmnet: VMNetConnect: returning port userif10.
Feb 22 16:31:31 spitfire kernel[0]: vmnet: VMNET_SO_BINDTOHUB: port: paddr 00:50:56:f3:d0:c3
Feb 22 16:31:31 spitfire kernel[0]: vmnet: Hub 8
Feb 22 16:31:31 spitfire kernel[0]: vmnet: 	Port 0
Feb 22 16:31:31 spitfire kernel[0]: vmnet: 	Port 1
Feb 22 16:31:31 spitfire kernel[0]: vmnet: 	Port 2
Feb 22 16:31:31 spitfire kernel[0]: vmnet: 	Port 3
Feb 22 16:31:31 spitfire kernel[0]: vmnet: VNetUserIf_Create: created userif11.
Feb 22 16:31:31 spitfire kernel[0]: vmnet: VMNetConnect: returning port userif11.
Feb 22 16:31:31 spitfire kernel[0]: vmnet: VMNET_SO_BINDTOHUB: port: paddr 00:50:56:f5:37:e8
Feb 22 16:31:31 spitfire kernel[0]: vmnet: Hub 8
Feb 22 16:31:31 spitfire kernel[0]: vmnet: 	Port 0
Feb 22 16:31:31 spitfire kernel[0]: vmnet: 	Port 1
Feb 22 16:31:31 spitfire kernel[0]: vmnet: 	Port 2
Feb 22 16:31:31 spitfire kernel[0]: vmnet: 	Port 3
Feb 22 16:31:31 spitfire kernel[0]: vmnet: 	Port 4
Feb 22 16:31:31 spitfire kernel[0]: vmnet: VNetUserIfFree: freeing userif11.
Feb 22 16:31:54 spitfire kernel[0]: Sandbox: appleeventsd(24) deny file-read-metadata /Library
Feb 22 16:31:54 spitfire kernel[0]: Sandbox: appleeventsd(24) deny mach-lookup com.apple.ocspd
Feb 22 16:32:05 spitfire kernel[0]: Sandbox: appleeventsd(24) deny file-read-metadata /Library
Feb 22 16:32:05 spitfire kernel[0]: Sandbox: appleeventsd(24) deny mach-lookup com.apple.ocspd
Feb 22 16:32:21 spitfire kernel[0]: fsevents: watcher vmware-vmx (pid: 538) - Using /dev/fsevents directly is unsupported.  Migrate to FSEventsFramework
Feb 22 16:33:06 spitfire kernel[0]: fsevents: watcher vmware-vmx (pid: 538) - Using /dev/fsevents directly is unsupported.  Migrate to FSEventsFramework
Feb 22 16:42:08 spitfire kernel[0]: DeleteIsochEP: after abort there are still 125 active TDs
Feb 22 16:42:08 spitfire kernel[0]: DeleteIsochEP: after abort there are still 78 active TDs
Feb 22 16:42:32 spitfire kernel[0]: DeleteIsochEP: after abort there are still 125 active TDs
Feb 22 16:42:32 spitfire kernel[0]: DeleteIsochEP: after abort there are still 107 active TDs
Feb 22 16:42:38 spitfire kernel[0]: DeleteIsochEP: after abort there are still 124 active TDs
Feb 22 16:42:38 spitfire kernel[0]: DeleteIsochEP: after abort there are still 78 active TDs
Feb 22 16:43:05 spitfire kernel[0]: DeleteIsochEP: after abort there are still 126 active TDs
Feb 22 16:43:05 spitfire kernel[0]: DeleteIsochEP: after abort there are still 78 active TDs
Feb 22 16:43:09 spitfire kernel[0]: DeleteIsochEP: after abort there are still 124 active TDs
Feb 22 16:43:09 spitfire kernel[0]: DeleteIsochEP: after abort there are still 78 active TDs
Feb 22 16:43:31 spitfire kernel[0]: Sandbox: Kodi(768) System Policy: deny file-write-unlink /Users/rachel/Library/Saved Application State/org.xbmc.kodi.savedState/restorecount.plist
Feb 22 16:45:14 spitfire kernel[0]: thunderbird (map: 0xffffff80278bc2d0) triggered DYLD shared region unnest for map: 0xffffff80278bc2d0, region 0x7fff8b800000->0x7fff8ba00000. While not abnormal for debuggers, this increases system memory footprint until the target exits.
Feb 22 16:47:44 spitfire kernel[0]: DeleteIsochEP: after abort there are still 125 active TDs
Feb 22 16:47:44 spitfire kernel[0]: DeleteIsochEP: after abort there are still 77 active TDs
Feb 22 16:48:00 spitfire kernel[0]: nfs server twilight.local:/media/Reds: not responding
Feb 22 16:48:00 spitfire kernel[0]: nfs server twilight.local:/media/Reds: not responding
Feb 22 16:48:19 spitfire kernel[0]: nfs_connect: socket connect taking a while for twilight.local:/media/Reds
Feb 22 16:48:30 spitfire kernel[0]: nfs server twilight.local:/media/Reds: not responding
Feb 22 16:48:33 spitfire kernel[0]: nfs server twilight.local:/media/Reds: not responding
Feb 22 16:48:41 spitfire kernel[0]: nfs_connect: socket connect aborted for twilight.local:/media/Reds
Feb 22 16:48:41 spitfire kernel[0]: nfs server twilight.local:/media/Reds: can not connect, error 65
Feb 22 16:48:41 spitfire kernel[0]: nfs server twilight.local:/media/Reds: not responding
Feb 22 16:48:56 spitfire kernel[0]: DeleteIsochEP: after abort there are still 124 active TDs
Feb 22 16:48:56 spitfire kernel[0]: DeleteIsochEP: after abort there are still 126 active TDs
Feb 22 16:49:01 spitfire kernel[0]: nfs server twilight.local:/media/Reds: not responding
Feb 22 16:49:13 spitfire kernel[0]: nfs server twilight.local:/media/Reds: can not connect, error 65
Feb 22 16:49:21 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port userListener2.
Feb 22 16:49:21 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port userif10.
Feb 22 16:49:21 spitfire kernel[0]: vmnet: VNetUserIfFree: freeing userif10.
Feb 22 16:49:23 spitfire kernel[0]: vmmon: Cleaned up 780796 virtual main memory pages from VM.
Feb 22 16:49:23 spitfire kernel[0]: vmmon: Cleaned up 5754 monitor anonymous pages from VM.
Feb 22 16:49:23 spitfire kernel[0]: vmmon: Cleaned up 3580 user anonymous pages from VM.
Feb 22 16:49:25 spitfire kernel[0]: vmmon: PTSC: initialized at 3497374000 Hz using reference clock, TSCs are synchronized.
Feb 22 16:49:25 spitfire kernel[0]: vmmon: Cycles 73
Feb 22 16:49:25 spitfire kernel[0]: vmnet: VNetUserIf_Create: created userif12.
Feb 22 16:49:25 spitfire kernel[0]: vmnet: VMNetConnect: returning port userif12.
Feb 22 16:49:25 spitfire kernel[0]: vmnet: VMNET_SO_BINDTOHUB: port: paddr 00:50:56:fe:ce:d2
Feb 22 16:49:25 spitfire kernel[0]: vmnet: Hub 8
Feb 22 16:49:25 spitfire kernel[0]: vmnet: 	Port 0
Feb 22 16:49:25 spitfire kernel[0]: vmnet: 	Port 1
Feb 22 16:49:25 spitfire kernel[0]: vmnet: 	Port 2
Feb 22 16:49:25 spitfire kernel[0]: vmnet: 	Port 3
Feb 22 16:49:25 spitfire kernel[0]: vmnet: VNetUserIf_Create: created userif13.
Feb 22 16:49:25 spitfire kernel[0]: vmnet: VMNetConnect: returning port userif13.
Feb 22 16:49:25 spitfire kernel[0]: vmnet: VMNET_SO_BINDTOHUB: port: paddr 00:50:56:e0:38:e3
Feb 22 16:49:25 spitfire kernel[0]: vmnet: Hub 8
Feb 22 16:49:25 spitfire kernel[0]: vmnet: 	Port 0
Feb 22 16:49:25 spitfire kernel[0]: vmnet: 	Port 1
Feb 22 16:49:25 spitfire kernel[0]: vmnet: 	Port 2
Feb 22 16:49:25 spitfire kernel[0]: vmnet: 	Port 3
Feb 22 16:49:25 spitfire kernel[0]: vmnet: 	Port 4
Feb 22 16:49:25 spitfire kernel[0]: vmnet: VNetUserIfFree: freeing userif13.
Feb 22 16:49:29 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port userListener3.
Feb 22 16:49:29 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port userif12.
Feb 22 16:49:29 spitfire kernel[0]: vmnet: VNetUserIfFree: freeing userif12.
Feb 22 16:49:29 spitfire kernel[0]: vmmon: Cleaned up 11782 virtual main memory pages from VM.
Feb 22 16:49:29 spitfire kernel[0]: vmmon: Cleaned up 3804 monitor anonymous pages from VM.
Feb 22 16:49:29 spitfire kernel[0]: vmmon: Cleaned up 3579 user anonymous pages from VM.
Feb 22 16:49:29 spitfire kernel[0]: DeleteIsochEP: after abort there are still 124 active TDs
Feb 22 16:49:29 spitfire kernel[0]: DeleteIsochEP: after abort there are still 126 active TDs
Feb 22 16:49:30 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port userif2.
Feb 22 16:49:30 spitfire kernel[0]: vmnet: VNetUserIfFree: freeing userif2.
Feb 22 16:49:30 spitfire kernel[0]: vmnet: netif-vmnet1: SIOCSIFFLAGS: 0x8862
Feb 22 16:49:30 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port netif0.
Feb 22 16:49:30 spitfire kernel[0]: vmnet: netif-vmnet1: SIOCPROTODETACH failed: 16.
Feb 22 16:49:30 spitfire kernel[0]: vmnet: netif-vmnet1: Deleting protocol 2.
Feb 22 16:49:30 spitfire kernel[0]: vmnet: netif-vmnet1: Detaching...
Feb 22 16:49:30 spitfire kernel[0]: vmnet: netif-vmnet1: Detached.
Feb 22 16:49:30 spitfire kernel[0]: vmnet: Freeing hub ffffffffffe755df.
Feb 22 16:49:30 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port userif5.
Feb 22 16:49:30 spitfire kernel[0]: vmnet: VNetUserIfFree: freeing userif5.
Feb 22 16:49:30 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port userif3.
Feb 22 16:49:30 spitfire kernel[0]: vmnet: VNetUserIfFree: freeing userif3.
Feb 22 16:49:30 spitfire kernel[0]: vmnet: netif-vmnet8: SIOCSIFFLAGS: 0x8862
Feb 22 16:49:30 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port netif1.
Feb 22 16:49:30 spitfire kernel[0]: vmnet: netif-vmnet8: SIOCPROTODETACH failed: 16.
Feb 22 16:49:30 spitfire kernel[0]: vmnet: netif-vmnet8: Deleting protocol 2.
Feb 22 16:49:30 spitfire kernel[0]: vmnet: netif-vmnet8: Detaching...
Feb 22 16:49:30 spitfire kernel[0]: vmnet: netif-vmnet8: Detached.
Feb 22 16:49:30 spitfire kernel[0]: vmnet: Freeing hub ffffffffffe5e5df.
Feb 22 16:49:30 spitfire kernel[0]: vmnet: VMNetDisconnect: called for port bridge0.
Feb 22 16:49:30 spitfire kernel[0]: vmnet: bridge-en0: filter detached
Feb 22 16:49:30 spitfire kernel[0]: vmnet: bridge-en0: down
Feb 22 16:49:30 spitfire kernel[0]: vmnet: bridge-en0: detached
Feb 22 16:49:30 spitfire kernel[0]: vmnet: Freeing hub ffffffffffe8a5df.
Feb 22 16:49:30 spitfire kernel[0]: vmmon: Removing module.
Feb 22 16:49:30 spitfire kernel[0]: vmmon: Timer thread stopping...
Feb 22 16:49:30 spitfire kernel[0]: vmmon: Timer thread stopped.
Feb 22 16:49:30 spitfire kernel[0]: vmmon: Module removed.
Feb 22 16:49:30 spitfire kernel[0]: vmnet: Removing module.
Feb 22 16:49:30 spitfire kernel[0]: vmnet: Module removed.
Feb 22 16:49:30 spitfire kernel[0]: vsock: Removing module.
Feb 22 16:49:30 spitfire kernel[0]: vsock: End workloop.
Feb 22 16:49:30 spitfire kernel[0]: vsock: Module removed.
Feb 22 16:49:30 spitfire kernel[0]: vmci: Removing module.
Feb 22 16:49:30 spitfire kernel[0]: vmci: End helper queue thread.
Feb 22 16:49:30 spitfire kernel[0]: vmci: Module removed.
Feb 22 16:49:32 spitfire kernel[0]: nfs server twilight.local:/media/Reds: not responding
Feb 22 16:49:41 spitfire kernel[0]: Ethernet [IntelMausi]: Link down on en0
Feb 22 16:49:43 spitfire kernel[0]: nfs server twilight.local:/media/Reds: not responding
Feb 22 16:49:45 spitfire kernel[0]: nfs server twilight.local:/media/Reds: can not connect, error 65
Feb 22 16:49:49 spitfire kernel[0]: Ethernet [IntelMausi]: Link up on en0, 1-Gigabit, Full-duplex, Rx/Tx flow-control
Feb 22 16:49:49 spitfire kernel[0]: nfs server twilight.local:/media/Reds: connected
Feb 22 16:49:49 spitfire kernel[0]: nfs server twilight.local:/media/Reds: is alive again
Feb 22 16:49:49 spitfire kernel[0]: nfs server twilight.local:/media/Reds: not responding
Feb 22 16:49:49 spitfire kernel[0]: nfs server twilight.local:/media/Reds: is alive again
Feb 22 16:49:49 spitfire kernel[0]: nfs server twilight.local:/media/Reds: is alive again
Feb 22 16:50:06 spitfire kernel[0]: Ethernet [IntelMausi]: Tx stalled? Resetting chipset. txDirtyDescIndex=81, IMS=0x80020080.
Feb 22 16:50:06 spitfire kernel[0]: Ethernet [IntelMausi]: Link down on en0
Feb 22 16:50:11 spitfire kernel[0]: Ethernet [IntelMausi]: Link up on en0, 1-Gigabit, Full-duplex, Rx/Tx flow-control
Feb 22 16:50:28 spitfire kernel[0]: Ethernet [IntelMausi]: Tx stalled? Resetting chipset. txDirtyDescIndex=497, IMS=0x80020080.
Feb 22 16:50:28 spitfire kernel[0]: Ethernet [IntelMausi]: Link down on en0
Feb 22 16:50:32 spitfire kernel[0]: Ethernet [IntelMausi]: Link up on en0, 1-Gigabit, Full-duplex, Rx/Tx flow-control
Feb 22 16:50:37 spitfire kernel[0]: Ethernet [IntelMausi]: Link down on en0
Feb 22 16:50:45 spitfire kernel[0]: Ethernet [IntelMausi]: Link up on en0, 1-Gigabit, Full-duplex, Rx/Tx flow-control
Feb 22 16:50:46 spitfire kernel[0]: firefox (map: 0xffffff80256a34b0) triggered DYLD shared region unnest for map: 0xffffff80256a34b0, region 0x7fff8b800000->0x7fff8ba00000. While not abnormal for debuggers, this increases system memory footprint until the target exits.
Feb 22 16:52:16 spitfire kernel[0]: Sandbox: Kodi(866) System Policy: deny file-write-unlink /Users/rachel/Library/Saved Application State/org.xbmc.kodi.savedState/restorecount.plist
Feb 22 16:53:30 spitfire kernel[0]: DeleteIsochEP: after abort there are still 125 active TDs
Feb 22 16:53:30 spitfire kernel[0]: DeleteIsochEP: after abort there are still 94 active TDs
spitfire:log root# 

Plus related chatter from Finder and automountd as they struggle. An ssh session gets interrupted too I think.

[fffeee]

I see no evidence for a driver issue. Looks more like a misconfigured system. The driver has to stall the output queue when resources become exhausted. Obviously something is flooding the network stack with packets. Are you using some kind of file sharing software?

 

Check the kernel logs to find out what prevents the network interface from coming up and what prevents the login window from appearing because the login window doesn't depend on en0.

 

Mieze

 

Kind of, I use btsync to sync a couple of directories to my NAS, Hac desktop and rMBP, so fewer than half a dozen peers. 

 

My resource/descriptors issue hasn't occurred recently, using d3 driver. I need to raise some of the values for network and files/memory on my workstation anyway from defaults, it's possible some people getting stalled messages or having performance issues may want to consider some of my values; 

### kernel tuning
#   i have 32GB of memory but i also use zfs.
#   some of this tuning is in response to bottlenecking i've 
#   encountered.
#


kern.maxfiles=280000
kern.maxfilesperproc=20480
# kern.num_files=24270
kern.maxvnodes=280000
# i'm almost always using every single one of those ^
kern.maxproc=2500
kern.maxprocperuid=2400
kern.ipc.somaxconn=2500
kern.maxnbuf=60000
kern.num_taskthreads=2560


### if the OS X default of 3 is not big enough
# 

# net.inet.tcp.win_scale_factor=4

### increase OS X TCP autotuning maximums
#
# net.inet.tcp.autorcvbufmax=16777216
# net.inet.tcp.autosndbufmax=16777216


### stack tuning
#

# net.inet.tcp.v6mssdflt=1428
net.inet.tcp.mssdflt=1448
net.inet.tcp.v6mssdflt=1412
net.inet.tcp.msl=15000
net.inet.tcp.always_keepalive=0
net.inet.tcp.delayed_ack=3
net.inet.tcp.slowstart_flightsize=20
net.inet.tcp.local_slowstart_flightsize=9
net.inet.tcp.blackhole=2
net.inet.udp.blackhole=1

### adjusting send/recv space
# 

net.inet.tcp.sendspace=1042560
net.inet.tcp.recvspace=1042560

At home I don't have native ipv6 and use a tunnel from Hurricane Electric. I've been making some adjustments for that tunnel that may or may not be relevant (to anyone).

 

---

 

Footnote

While loginwindow doesn't depend on en0, but what was happening was because en0 wasn't there and my other interface was, the system hostname changed, and there was an install or update that was unable to get focus above loginwindow without blocking display of both for whatever reason. Found a couple of people on Apple support forums that had the same issue where loginwindow is just a black screen and a cursor, you can circumvent by blindly logging in (workstations that don't require username and password can use the tab key and type the first letter of username shown to get it highlighted (even though you can't see it) and hit enter and type your password and hit enter and then finally see the dialog, or you can do the nuclear option and blow away the contents of /var/folders where AppStore or softwareupdate or whatever stashed the "now do this on boot" cruft that is holding you up.) Haven't had en0/intel-onboard fail lately so maybe the two were related.

[Mieze]

First of all, thanks for the log data! Now let's summarize what we have because there are two different problems caused by VMware:

1. The first problem is, that VMware sometimes messes up the network stack so that you have to use ifconfig up/down in order to revive it. This problem is independent of the driver.
2. The second one is that VMware seems to alter packets in a way so that they cause a transmitter deadlock. As strangeNoises is using the same NIC as I do for development (I217V rev. 5) and the driver is working absolutely stable on my test system, I'm quite sure that VMware is the key to a solution. Although I haven't worked with VMware, I have some experience with Parallels Desktop and VirtualBox. I know that virtualization software installs its own kexts which are deeply interfering with the OS even when no VM is running, making the fact that the deadlocks continue to occur after shutting down the VMs irrelevant.

tarasis sent me some log data which he collected with the debug version. They include dumps of the packet which caused the problem. I'm going to analyze these packets bit by bit in order to find out what exactly causes the deadlock.

 

Mieze

[Mieze]

Ok, I found something. Looks like VMware is killing TSO because the packets causing the tx deadlock are TSO4 operations. According to Intel's datasheet the Total Length field of the IP header should be set to zero, but in a packet that caused a deadlock it wasn't. See for yourself:

IP-Header:  
	Version: 0x4
	Length: 0x5
	TOS: 0x20
	Total Length: 0x0b84 (2948) <--- Should be 0.
	ID: 0x32 0xc9
	Flags: 0x4
	Frag. Offset: 0x000
	TTL: 0x40
	Protocol: 0x06
	CSum: 0x00 0x00
	Source: 0xc0 0xa8 0x00 0x26 (192.168.0.38)
	Dest.: 0xc0 0xa8 0x00 0xd5 (192.168.0.218)

I published version 1.0.0d4 moments ago which zeros the total length field of the IP-header for TSO4 operations. I hope this will resolve the issue with VMware.

 

Good luck!

 

Mieze

Edited February 25, 2015 by Mieze

[fffeee]

1. /* snip */ I know that virtualization software installs its own kexts which are deeply interfering with the OS even when no VM is running, making the fact that the deadlocks continue to occur after shutting down the VMs irrelevant.

 

VMWare Fusion's network extensions are in /Applications/VMware\ Fusion.app/Contents/Library/kexts, and they're not running until a VM is started.

 

It uses their natd for network configurations that use NAT, and creates vmnet[n] network interfaces it uses for bridged/nat/private networks. At a glance it looks like the same natd they use on ESXi.

 

Their vm-net tools do you let up/down and create/destroy interfaces ad-hoc but you are correct that the kexts stay loaded (but without anything to do if the interfaces are destroyed). If the presence of the extensions alone is a possible culprit in spite of not having interfaces to manage, that would be rather interesting.

[Mieze]

VMWare Fusion's network extensions are in /Applications/VMware\ Fusion.app/Contents/Library/kexts, and they're not running until a VM is started.

 

This would explain why StrangeNoises didn't have any problems until she started using VMware again.

[tarasis]

I published version 1.0.0d4 moments ago which zeros the total length field of the IP-header for TSO4 operations. I hope this will resolve the issue with VMware.

 

Thank you Mieze, I will test it out tomorrow. Sounds like you've probably nailed it.

[Mieze]

Their vm-net tools do you let up/down and create/destroy interfaces ad-hoc but you are correct that the kexts stay loaded (but without anything to do if the interfaces are destroyed). If the presence of the extensions alone is a possible culprit in spite of not having interfaces to manage, that would be rather interesting.

 

As network kernel extensions they have full access to any inbound/outbound packet with the ability to inject, modify or filter out any packet before it reaches the driver/network stack as long as they are unloaded at some point in time. Unless you have reverse engineered their kext you don't know what they are actually doing and the fact that shutting down VMs doesn't resolve the problem immediately is hard to reconcile with your arguments.

 

Thank you Mieze, I will test it out tomorrow. Sounds like you've probably nailed it.

 

I hope it will resolve the issue but I wouldn't bet on it. Actually we don't know what VMware is doing to the packets but I'm very keen to see what happens.

 

Mieze 

[StrangeNoises]

This would explain why strangeNoises didn't have any problems until she started using VMware again.

Hm. To be very specific about the sequence of events in the solitary problem I had afterwards:

 

I had copied my big files out of the virtual machine to a local disk, but I actually wanted them on a remote NFS share. So while VMWare was still running, I started copying those files across using the OSX Finder.

 

The Windows Update download stalled, the network failed.

 

I shutdown VMWare for the last time.

 

I did the ifconfig down/up.

 

The ongoing OSX Finder NFS transfer tried to resume, but soon stalled again. Here is where the "tx stalled" messages from IntelMausi occurred.

 

I stopped the transfer in the Finder. Then did the ifconfig down/up again. Since then it's been fine.

 

So we're talking about a transfer process which - if memory doesn't fail me - had started while the VMWare guest was still running, and before I lost the network again. So I can believe that transfer had some state associated with it that dates from when VMWare still had active interfaces, even though the specific transfer wasn't using them.

 

Anyway, will install the -d4 driver tomorrow and to a specific vmware test then.

[tluck]

@mieze - likewise will test -d4. I was using vmware yesterday and it again did cause the network hang after awhile. getting it to hang seems to be a bit random but definitely related to VMware. 

[tarasis]

Is this happening to anyone else?

 

I installed the d4 version and constantly panic'ing on boot, even trying to get into Safe mode. See attached photo.

 

Just tried -x UseKernelCache=No (and Yes) but no change

 

-- Edit --

 

Thankfully I had a bootable clone. (Running D3 Release)

 

Removing the d4 version I could boot into OSX.

I tried again with a fresh copy of d4 (copied over, used Kext Utility) and it panicked again on boot,

Put d3 (Debug) back and it also panicked on boot, (odd this worked before, as I used it to send logs to Mieze)

Booted into Win7, that's fine & network was working

 

Need to stop and get my kids from school, very confused right now!

[StrangeNoises]

Is this happening to anyone else?

 

I installed the d4 version and constantly panic'ing on boot, even trying to get into Safe mode. See attached photo.

 

Just tried -x UseKernelCache=No (and Yes) but no change.

 

Foolishly I took your post as a reminder to install -d4 myself and...

 

Working for me. :-) (As in, it boots, I have network; yet to test the VMWare thing. Booting just told me I have a degraded raid1 set. I ought to deal with that first. :-})

[Mieze]

Is this happening to anyone else?

 

I installed the d4 version and constantly panic'ing on boot, even trying to get into Safe mode. See attached photo.

 

Just tried -x UseKernelCache=No (and Yes) but no change

 

-- Edit --

 

Thankfully I had a bootable clone. (Running D3 Release)

 

Removing the d4 version I could boot into OSX.

I tried again with a fresh copy of d4 (copied over, used Kext Utility) and it panicked again on boot,

Put d3 (Debug) back and it also panicked on boot, (odd this worked before, as I used it to send logs to Mieze)

Booted into Win7, that's fine & network was working

 

Need to stop and get my kids from school, very confused right now!

 

It seems that the system got damaged during the installation. After reading your post I installed it on my 10.10.2 test system and it works as expected (tried only 10.9.5 yesterday before publishing it).

 

Mieze 

[tarasis]

Okay, arse. Thanks!

I guess maybe I hadn't properly removed the Ethernet in preferences (removed, but not hit apply) before putting the new driver in place.

It's totally consistent, I put any version of the Mausi driver in place, and the system panics in boot. I remove the driver and it boots fine. So I apparently messed something up.

going to dig as I'd rather not reinstall the OS (replaced Extensions dir completely, still occurred, spotted Mausi mentioned during boot, so something is still trying to load it) but it's looking like I need to.

 

--- Edit --

 

Back! and running with d4

 

I booted my Clone, created a timestamp file, made a change to the network preferences, and used find to find all files that changed since the timestamp.

 

I (effectively) deleted /Library/Preferences/SystemConfiguration/NetworkInterfaces.plist and /Library/Preferences/SystemConfiguration/preferences.plist which seemed to do the trick.

 

When I rebooted (with the d4 driver in /S/L/E) it booted up fine but without ethernet, ran kext utility to fix permission & ownership on Mausi kext, rebooted, went to System Preferences->Network and setup Ethernet again.

26/02/2015 15:14:28.000 kernel[0]: Ethernet [IntelMausi]: TCP/IPv6 segmentation offload enabled.
26/02/2015 15:14:28.000 kernel[0]: Ethernet [IntelMausi]: TCP/IPv6 checksum offload enabled.
26/02/2015 15:14:28.000 kernel[0]: Ethernet [IntelMausi]: Version 1.0.0d4 using max interrupt rate 7000.
26/02/2015 15:14:28.000 kernel[0]: Ethernet [IntelMausi]: intrThrValue=557
26/02/2015 15:14:28.000 kernel[0]: Ethernet [IntelMausi]: PCI power management capabilities: 0xc822.
26/02/2015 15:14:28.000 kernel[0]: Ethernet [IntelMausi]: PME# from D3 (cold/hot) supported.
26/02/2015 15:14:28.000 kernel[0]: Ethernet [IntelMausi]: I218V2 (Rev. 0) at 0xffffff81ea81d000, 78:24:af:8c:dc:af
26/02/2015 15:14:28.000 kernel[0]: Ethernet [IntelMausi]: MSI interrupt index: 0
26/02/2015 15:14:28.000 kernel[0]: Ethernet [IntelMausi]: kIOEthernetWakeOnMagicPacket added to filters.
26/02/2015 15:14:28.000 kernel[0]: Ethernet [IntelMausi]: Already in power state 1.
26/02/2015 15:14:42.000 kernel[0]: Ethernet [IntelMausi]: No medium selected. Falling back to autonegotiation.
26/02/2015 15:14:46.000 kernel[0]: Ethernet [IntelMausi]: checkLinkStatus() returned 1.
26/02/2015 15:14:46.000 kernel[0]: Ethernet [IntelMausi]: EEE mode = 0x0000, adv=0x0006, lpa=0x0000
26/02/2015 15:14:46.000 kernel[0]: Ethernet [IntelMausi]: Link up on en1, 1-Gigabit, Full-duplex, Rx/Tx flow-control

Now back to your regularly scheduled broadcast.

Edited February 26, 2015 by tarasis

[wastez]

Your newest version is faster again.

 

On d3 the write speed went from over 100 mb/s to 80 mb/s.

On d4 the write speed is constant again over 100 mb/s.

 

Your driver is soooo much faster then the old one.... Really great.

 

On d4 i got the following error in log:

Ethernet [IntelMausi]: replaceOrCopyPacket() failed.

[Mieze]

 

Your newest version is faster again.

 

On d3 the write speed went from over 100 mb/s to 80 mb/s.

On d4 the write speed is constant again over 100 mb/s.

 

Your driver is soooo much faster then the old one.... Really great.

 

On d4 i got the following error in log:

Ethernet [IntelMausi]: replaceOrCopyPacket() failed.

 

Strange, because I didn't change anything which might be relevant for performance so that the speed bump must be due to any side effect outside of the driver.

 

This error message is a harmless memory management issue and is self healing. It means that the driver had to drop a received packet because it wasn't able to allocate a new buffer.

 

Mieze

[Mieze]

First of all, I must confess that version 1.0.0d4 made things worse. After analyzing log data I received from tarasis, it seems that while VMware is active, packets which are retransmitted by the network stack are handed over to the driver a second time without updating the header so that setting

 

ipHdr->tot_len = 0;

 

was an extremely stupid idea because the driver will be unable to calculate the payload size when faced with the packet the second time. That's why I have to revert the change I made.

 

Mieze

[Mieze]

I just posted version 1.0.0d5 with reworked TSO4 support in order to circumvent the issue in 1.0.0d4. It also includes additional debug code to collect more information about the VMware related problem. According to my findings it isn't a TSO specific problem as kernel logs from tarasis showed transmitter deadlocks while doing non-TSO operations.

 

As of now I'm at a loss but will continue the search for a solution.

 

Mieze