Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Conflict with SD card in MacBook Air #23

Open
cmrcx opened this issue May 5, 2014 · 4 comments
Open

Conflict with SD card in MacBook Air #23

cmrcx opened this issue May 5, 2014 · 4 comments

Comments

@cmrcx
Copy link

cmrcx commented May 5, 2014

If I execute "setprop sys.config.usb rndis" on my Android phone while an SD card is in the card reader of my MacBook Air, OS X shows the message, that the SD card was not properly unmounted. Also the tethering connection does not work then. Sometimes it works first, but disconnects after a short time.

system.log on the Mac:

May  5 08:11:31 mba-cmr kernel[0]: HoRNDIS: dataReadComplete: I/O aborted: device unplugged?
May  5 08:11:31 mba-cmr kernel[0]: HoRNDIS: message: kIOMessageServiceIsTerminated
May  5 08:11:31 mba-cmr kernel[0]: CoreStorage::recover() PV FB8513C6-6097-4425-B8AA-ED98A3A4DE1E from group "StorEDGE" (C55F0EAA-197E-488A-B78B-36AFF130886D) has been marked missing.
May  5 08:11:31 mba-cmr.lan com.apple.kextd[12]: LVG changed
May  5 08:11:31 mba-cmr kernel[0]: disk3: media is not present.
May  5 08:11:31 --- last message repeated 4 times ---
May  5 08:11:31 mba-cmr kernel[0]: jnl: disk3: do_jnl_io: strategy err 0x6
May  5 08:11:31 mba-cmr kernel[0]: jnl: disk3: write_journal_header: error writing the journal header!
May  5 08:11:31 mba-cmr kernel[0]: disk3: media is not present.
May  5 08:11:31 --- last message repeated 6 times ---
May  5 08:11:31 mba-cmr kernel[0]: hfs: unmount initiated on StorEDGE on device disk3
May  5 08:11:31 mba-cmr kernel[0]: jnl: disk3: close: journal 0xffffff8014b3ec20, is invalid.  aborting outstanding transactions
May  5 08:11:32 mba-cmr kernel[0]: AppleUSBMultitouchDriver::message - kIOUSBMessagePortHasBeenReset.
May  5 08:11:32 mba-cmr kernel[0]: AppleUSBMultitouchDriver::checkStatus - received Status Packet, Payload 2: device was reinitialized
May  5 08:11:32 mba-cmr.lan hidd[98]: MultitouchHID: device bootloaded
May  5 08:11:37 mba-cmr kernel[0]: CoreStorage: terminating group "StorEDGE" (C55F0EAA-197E-488A-B78B-36AFF130886D) is BUSY
May  5 08:11:37 mba-cmr kernel[0]: com_apple_driver_AppleUSBCardReaderUMC:: Stop::Controller Reset
May  5 08:11:37 mba-cmr.lan fseventsd[44]: disk logger: failed to open output file /Volumes/StorEDGE/.fseventsd/0000000000037cb6 (No such file or directory). mount point /Volumes/StorEDGE/.fseventsd
May  5 08:11:37 --- last message repeated 1 time ---
May  5 08:11:37 mba-cmr kernel[0]: HoRNDIS: init: HoRNDIS tethering driver for Snow Leopard+, by Joshua Wise
May  5 08:11:37 mba-cmr kernel[0]: HoRNDIS: rndisInit: their MTU 1486
May  5 08:11:37 mba-cmr kernel[0]: HoRNDIS: setMaxTransferUnit: Excuse me, but I said you could have an MTU of 1486, but you just tried to set an MTU of 1500.  Good try, buddy.
May  5 08:11:37 mba-cmr kernel[0]: HoRNDIS: init: starting up with MTU 1486
May  5 08:11:37 mba-cmr kernel[0]: in6_domifattach: in6_ifattach_prelim returned 22 if=en3
May  5 08:11:37 mba-cmr.lan configd[18]: [ifutil.c:774] inet6_set_perform_nud(): SIOCGIFINFO_IN6(en3) failed, Invalid argument
May  5 08:11:37 mba-cmr.lan configd[18]: siocll_start(en3) failed, Invalid argument (22)
May  5 08:11:37 mba-cmr kernel[0]: 0        1 AppleUSBCDCACMData: start - Find CDC driver for ACM data interface failed
May  5 08:11:37 mba-cmr kernel[0]: 0        1 AppleUSBCDCECMData: start - Find CDC driver for ECM data interface failed
May  5 08:11:38 mba-cmr kernel[0]: AppleUSBMultitouchDriver::message - kIOUSBMessagePortHasBeenReset.
May  5 08:11:38 mba-cmr kernel[0]: AppleUSBMultitouchDriver::checkStatus - received Status Packet, Payload 2: device was reinitialized
May  5 08:11:38 mba-cmr.lan hidd[98]: MultitouchHID: device bootloaded
May  5 08:11:38 mba-cmr kernel[0]: USBMSC Identifier (non-unique): 000000000310 0x5ac 0x8404 0x310, 2
May  5 08:11:40 mba-cmr kernel[0]: CoreStorage: fsck_cs has finished for group "C55F0EAA-197E-488A-B78B-36AFF130886D" with status 0x00
May  5 08:11:40 mba-cmr.lan com.apple.kextd[12]: LVG changed
May  5 08:11:40 mba-cmr kernel[0]: CoreStorageFamily::unlockVEKs() failed to unwrap the vek, status = e00002bc
May  5 08:11:40 mba-cmr.lan com.apple.kextd[12]: LVG changed
May  5 08:11:40 mba-cmr kernel[0]: jnl: disk3: replay_journal: from: 673792 to: 1901056 (joffset 0x3bf000)
May  5 08:11:41 mba-cmr.lan AirPlayUIAgent[252]: 2014-05-05 08:11:41.253931 AM [AirPlayUIAgent] Changed PIN pairing: no
May  5 08:11:41 mba-cmr.lan AirPlayUIAgent[252]: 2014-05-05 08:11:41.282345 AM [AirPlayUIAgent] Changed PIN pairing: no
May  5 08:11:41 mba-cmr kernel[0]: jnl: disk3: journal replay done.
May  5 08:11:41 mba-cmr kernel[0]: hfs: mounted StorEDGE on device disk3
May  5 08:11:41 mba-cmr.lan diskmanagementd[1936]: mount blocked by dissenter PID=0 (unknown) status=0xf8da0002 log=kDAReturnBusy message=(null)

Without the SD card inserted tethering works fine most of the time. Inserting the SD card when the tethering connection was already established, makes no problems.

The MacBook Air is a 13" mid 2011 with OS X 10.9.2. The SD card is a PNY StorEDGE 128GB. The phone is a Fairphone with Android 4.2.2 (Fairphone OS 1.1 Caju).

Any idea what's going on there?
@jwise
Copy link
Owner

jwise commented May 5, 2014

That is super super super weird.

Note also that the touchpad is being reset too ('AppleUSBMultitouchDriver').

The only thing that HoRNDIS knows is that out of nowhere, the device that it thought it was talking to went away. Looks like the USB hub it's attached to internally just loses its mind sometimes?

That's super freaky, but unfortunately I've got no idea why it happens :( Signs point to it being a bug somewhere else in the USB stack (it's probably not the phone's fault; the phone shouldn't be able to cause that), but I don't have enough experience with the way USB is set up on the Mac to be able to tell you what exactly is going on...

@cmrcx
Copy link
Author

cmrcx commented May 6, 2014

Thank you for the quick reply!

The touchpad reset also happens when tethering works fine (without the SD card):

May  6 19:45:45 mba-cmr.lan com.apple.kextd[12]: kext com.joshuawise.kexts.HoRNDIS  100001001 is in exception list, allowing to load
May  6 19:45:45 mba-cmr kernel[0]: HoRNDIS: init: HoRNDIS tethering driver for Snow Leopard+, by Joshua Wise
May  6 19:45:45 mba-cmr kernel[0]: HoRNDIS: rndisInit: their MTU 1486
May  6 19:45:45 mba-cmr kernel[0]: HoRNDIS: setMaxTransferUnit: Excuse me, but I said you could have an MTU of 1486, but you just tried to set an MTU of 1500.  Good try, buddy.
May  6 19:45:45 mba-cmr kernel[0]: HoRNDIS: init: starting up with MTU 1486
May  6 19:45:45 mba-cmr kernel[0]: in6_domifattach: in6_ifattach_prelim returned 22 if=en3
May  6 19:45:45 mba-cmr.lan configd[17]: [ifutil.c:774] inet6_set_perform_nud(): SIOCGIFINFO_IN6(en3) failed, Invalid argument
May  6 19:45:45 mba-cmr.lan configd[17]: siocll_start(en3) failed, Invalid argument (22)
May  6 19:45:45 mba-cmr kernel[0]: HoRNDIS: setMaxTransferUnit: Excuse me, but I said you could have an MTU of 1486, but you just tried to set an MTU of 1500.  Good try, buddy.
May  6 19:45:45 mba-cmr kernel[0]: bridge100: attached with 1 suspended link-layer multicast membership(s)
May  6 19:45:45 mba-cmr.lan com.apple.InternetSharing[813]: InternetSharing: com.apple.InternetSharing.broadcast-15 has been started
May  6 19:45:45 mba-cmr kernel[0]: en3: promiscuous mode enable succeeded
May  6 19:45:45 mba-cmr.lan com.apple.InternetSharing[813]: BCAST is ready [en2, mtu=1500, 0 DNSv6 server(s)]
May  6 19:45:45 mba-cmr kernel[0]: bridge100: successfully restored 1 suspended link-layer multicast membership(s) (err=0)
May  6 19:45:45 mba-cmr kernel[0]: HoRNDIS: receivePacket: non-PACKET over data channel? (msg_type deadbeef)
May  6 19:45:45 mba-cmr.lan com.apple.InternetSharing[813]: added addr=192.168.2.1 mask=255.255.255.0 on bridge100
May  6 19:45:45 mba-cmr kernel[0]: in6_domifattach: in6_ifattach_prelim returned 22 if=en3
May  6 19:45:45 mba-cmr.lan configd[17]: siocll_start(en3) failed, Invalid argument (22)
May  6 19:45:45 mba-cmr.lan com.apple.InternetSharing[813]: com.apple.InternetSharing.broadcast-15 started: [DHCP subnet=192.168.2/24 on bridge100 mtu=1486 <---> en2 mtu=1500] max-mss=1446
May  6 19:45:45 mba-cmr.lan com.apple.InternetSharing[813]:   dns: 192.168.2.1
May  6 19:45:45 mba-cmr.lan com.apple.InternetSharing[813]: started dns proxy
May  6 19:45:45 mba-cmr.lan mDNSResponder[46]: SetupDNSProxySkts: 26, 27, 28, 93
May  6 19:45:45 mba-cmr.lan com.apple.InternetSharing[813]: dns proxy successfully enabled
May  6 19:45:45 mba-cmr.lan com.apple.InternetSharing[813]: started "natpmpd"
May  6 19:45:45 mba-cmr.lan configd[17]: siocll_start(en3) failed, Invalid argument (22)
May  6 19:45:45 --- last message repeated 1 time ---
May  6 19:45:45 mba-cmr kernel[0]: **** [IOBluetoothHostControllerUSBTransport][SuspendDevice] -- Resume -- suspendDeviceCallResult = 0x0000 (kIOReturnSuccess) -- 0x0400 ****
May  6 19:45:45 mba-cmr kernel[0]: 0        1 AppleUSBCDCACMData: start - Find CDC driver for ACM data interface failed
May  6 19:45:45 mba-cmr kernel[0]: 0        1 AppleUSBCDCECMData: start - Find CDC driver for ECM data interface failed
May  6 19:45:46 mba-cmr kernel[0]: AppleUSBMultitouchDriver::message - kIOUSBMessagePortHasBeenReset.
May  6 19:45:46 mba-cmr kernel[0]: AppleUSBMultitouchDriver::checkStatus - received Status Packet, Payload 2: device was reinitialized
May  6 19:45:46 mba-cmr.lan hidd[96]: MultitouchHID: device bootloaded
May  6 19:45:55 mba-cmr.lan AirPlayUIAgent[333]: 2014-05-06 07:45:55.485946 PM [AirPlayUIAgent] Changed PIN pairing: no
May  6 19:45:55 mba-cmr.lan AirPlayUIAgent[333]: 2014-05-06 07:45:55.504863 PM [AirPlayUIAgent] Changed PIN pairing: no
May  6 19:46:23 mba-cmr kernel[0]: **** [IOBluetoothHostControllerUSBTransport][SuspendDevice] -- Suspend -- suspendDeviceCallResult = 0x0000 (kIOReturnSuccess) -- 0x0400 ****
May  6 19:46:53 mba-cmr kernel[0]: HoRNDIS: receivePacket: msg_len too big?
May  6 19:46:53 mba-cmr kernel[0]: HoRNDIS: receivePacket: non-PACKET over data channel? (msg_type 17387d13)
May  6 19:48:17 mba-cmr kernel[0]: HoRNDIS: receivePacket: non-PACKET over data channel? (msg_type 20544547)

I installed Apple IOUSBFamily Log now, which gives me very detailed logs. On the log level 1 (least detail) it looks like if the touchpad is not the only USB device being reset:

May  6 19:45:45.939  [1]        Apple Internal Keyboard / Trackpad[0xffffff800e556200]::_GetConfiguration  failed GET_CONFIG with error 0xe00002eb (operation was aborted)
May  6 19:45:45.947  [1]        Card Reader[0xffffff801e9a6200]::_GetConfiguration  failed GET_CONFIG with error 0xe00002ed (device is not responding)
May  6 19:45:45.947  [1]        IOUSBDeviceUserClientV2[0xffffff80131b3c00]::start -  Apple USB Ethernet Adapter required admin privileges, but task did not have them!
May  6 19:45:46.024  [1]        IOUSBDeviceUserClientV2[0xffffff800ebf3600]::start -  Apple USB Ethernet Adapter required admin privileges, but task did not have them!
May  6 19:45:46.184  [1]        IOUSBDeviceUserClientV2[0xffffff80131b3c00]::start -  Apple USB Ethernet Adapter required admin privileges, but task did not have them!
May  6 19:45:46.191  [1]        IOUSBDeviceUserClientV2[0xffffff800e4e5200]::start -  Apple USB Ethernet Adapter required admin privileges, but task did not have them!
May  6 19:45:46.197  [1]        IOUSBDeviceUserClientV2[0xffffff800e4e5200]::start -  Apple USB Ethernet Adapter required admin privileges, but task did not have them!
May  6 19:45:46.337  [1]        IOUSBHIDDriver(AppleUSBTCButtons)[0xffffff800e6c7e00]: Detected an kIONotResponding error but still connected.  Resetting port
May  6 19:45:46.340  [1]        AppleUSBHubPort[0xffffff800e40d400]::Resetting device Apple Internal Keyboard / Trackpad:  port 2 of Hub at 0xfa100000
May  6 19:45:46.344  [1]        IOUSBHIDDriver(AppleUSBTCKeyboard)[0xffffff800e589400]: Detected an kIONotResponding error but still connected.  Resetting port
May  6 19:45:46.344  [1]        (Apple Internal Keyboard / Trackpad)[0xffffff800e556200]::_ResetDevice - reset already in progress - returning kIOReturnNotPermitted
May  6 19:45:47.014  [1]        AppleUSBHubPort[0xffffff800e3c7800]::Resetting device Card Reader:  port 1 of Hub at 0xfd100000

@jwise
Copy link
Owner

jwise commented May 7, 2014

That last log makes me inclined to believe that there's something weird hardware-related going on, but of course that is because I am wearing my software developer hat :-)

I really do wonder what's going on. If you find out more going forward, please continue to keep me updated.

@cmrcx
Copy link
Author

cmrcx commented May 8, 2014

The problem was caused by Google's "Android File Transfer" http://www.android.com/filetransfer/. I uninstalled this crap and everything works fine now.

Thank you for this extremely helpful driver, Joshua!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@jwise @cmrcx