Mailing Lists: Apple Mailing Lists
Image of Mac OS face in stamp
Re: Replacement for IOUSBFamily log?
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

Re: Replacement for IOUSBFamily log?



Eric,

(Sorry for the formatting but the list server barfs on emails > 24K, so my pretty RTF email got bounced):

It is indeed unfortunate that the logging version is not available.  Since the sources are also not open-sourced either, then you are in a lot of hurt if you want to get insight into what’s going on inside the USB stack.  As you’ve mentioned, dtrace is an option and I’ll give you a couple of probe points that you can use.  The kernel tracepoint tool for USB, usbtracer, also will work.  This tool was released via the Debug IOUSBFamily package.  Here’s what you can do: (BTW, I’m doing this on Yosemite 10.10.1):

1.  Download the last available Debug kit from the Developer website.  I find the one for 10.9.4 at: (You have to be logged into the developer portal for this to work, I believe):

https://developer.apple.com/downloads/index.action?q=IOUSB

2.  Mount the “-log” disk image and extract the files with the following command (cd to a temporary directory):

$ sudo pax -r -v -z -f /Volumes/IOUSBFamily-683.4.0-log/IOUSBFamily-683.4.0-log/IOUSBFamily-683.4.0-log.pkg/Contents/Archive.pax.gz

3.  Look into the DevTools/Hardware folder that is extracted.  You’ll find the USB Prober.app there, which is still handy even if you don’t get the logging.  This build runs fine on Yosemite.

4.  Run the tool ‘usbtracer’ in the Resources folder of the USB Prober.app:

Nano:/DevTools/Hardware/USB Prober.app/Contents/Resources% sudo ./usbtracer
Password:
usbtracer version:  "680.4.1"
09:28:39 [80395557500][         0 us] -> XHCI::Begin Primary Interrupt  (0xffffff81a06d3000)
09:28:39 [80395557501][         1 us]    XHCI::Primary Interrupt        (0xffffff81a06d3000) isInactive: 0, _controllerAvailable: 0
09:28:39 [80395557508][         7 us]    XHCI::Primary Interrupt        (0xffffff81a06d3000) interrupt pending: true MFINDEX:0x0000127f
09:28:39 [80395557514][         6 us]    XHCI::Primary Interrupt        (0xffffff81a06d3000) IMOD:0x000000a0  IMAN: 0x00000002
09:28:39 [80395557515][         1 us] -> XHCI::Begin FilterEventRing    (0xffffff81a06d3000) ---> IRQ[0]

This will give you a LOT of information and it will sometimes have undecoded trace points (because we are using the 10.9.4 version of the tool under 10.10.1), which won’t be very helpful:

09:29:59 [80475899630][        12 us] <- F-0x052d|00|044  ffffff81a06d3000                 0                 0                 0  0x             246   0

But it can also give you information like what type of control request was issued:

09:30:01 [80476970379][         0 us] -> Controller::Control Start      (0xffffff81a06d3000) Bus: 0x40, Address: 28, Endpoint: 0, (in)  bmRequestType: 0x80, bRequest: 0x06, wValue: 0x0100, wIndex: 0x0000, wLength: 0x0012 (GET_DESCRIPTOR (Device))

and the actual data from that request:

09:30:01 [80476971504][         3 us]    Controller::Packet Handler     (0x0000000000000000) Bus: 0x40, Address: 28, Endpoint: 0, (in)  length: 18, data: 0x1201000200000008 0x6d0418c504420102

The tools is VERY verbose but *could* be helpful. It also does not require any special version of the USB stack — works with what ships.  The downside is that the tool won’t decode any new tracepoints that have been added.


As far as dtrace probes, you can get call stacks (and if you know the API you can even see the values of the parameters or the return value.  Here are some examples:

1.  To see all IOUSBDevice object calls:

sudo dtrace -n '*:*:*IOUSBDevice*:entry { stack(); }'

which will give you the kernel stack when the call was made, e.g.:

  6 298880 _ZN11IOUSBDevice11GetVendorIDEv:entry
              IOUSBFamily`IOUSBPipe::ControlRequest(IOUSBDevRequestDesc*, unsigned int, unsigned int, IOUSBCompletion*)+0x4f
              IOUSBFamily`IOUSBDevice::_DeviceRequestDescWithTimeout(OSObject*, void*, void*, void*, void*)+0xd9
              kernel`IOCommandGate::runAction(int (*)(OSObject*, void*, void*, void*, void*), void*, void*, void*, void*)+0x198
              IOUSBFamily`IOUSBDevice::DeviceRequest(IOUSBDevRequestDesc*, unsigned int, unsigned int, IOUSBCompletion*)+0x8e
              IOUSBFamily`IOUSBDeviceUserClientV2::DeviceRequestIn(unsigned char, unsigned char, unsigned short, unsigned short, unsigned long long, unsigned long long, unsigned int, unsigned int, IOUSBCompletion*)+0xf4
              IOUSBFamily`IOUSBDeviceUserClientV2::_DeviceRequestIn(IOUSBDeviceUserClientV2*, void*, IOExternalMethodArguments*)+0xec
              kernel`IOUserClient::externalMethod(unsigned int, IOExternalMethodArguments*, IOExternalMethodDispatch*, OSObject*, void*)+0x1cf
              kernel`is_io_connect_async_method+0x1f5
              kernel`0xffffff80015ea010+0x2c7
              kernel`ipc_kobject_server+0xfc
              kernel`ipc_kmsg_send+0x123
              kernel`mach_msg_overwrite_trap+0xcd
              kernel`mach_call_munger64+0x182
              kernel`hndl_mach_scall64+0x16

Using “ustack()”, will give you the user stack instead:

  6 298838 _ZN11IOUSBDevice29_DeviceRequestDescWithTimeoutEP8OSObjectPvS2_S2_S2_:entry
              libsystem_kernel.dylib`mach_msg_trap+0xa
              IOKit`io_connect_async_method+0x1e1
              IOKit`IOConnectCallAsyncScalarMethod+0x99
              IOUSBLib`IOUSBDeviceClass::DeviceRequestAsync(IOUSBDevRequestTO*, void (*)(void*, int, void*), void*)+0x16d
              IOUSBLib`IOUSBDeviceClass::deviceDeviceRequestAsync(void*, IOUSBDevRequest*, void (*)(void*, int, void*), void*)+0x58
              usbmuxd`0x000000010000c3ed+0x59
              usbmuxd`0x000000010000c358+0x11
              CoreFoundation`__CFRUNLOOP_IS_CALLING_OUT_TO_A_TIMER_CALLBACK_FUNCTION__+0x14
              CoreFoundation`__CFRunLoopDoTimer+0x423
              CoreFoundation`__CFRunLoopDoTimers+0x12d
              CoreFoundation`__CFRunLoopRun+0x7e8
              CoreFoundation`CFRunLoopRunSpecific+0x128
              CoreFoundation`CFRunLoopRun+0x61
              usbmuxd`0x0000000100001e8f+0x4f0
              usbmuxd`0x00000001000017e8+0x34
              usbmuxd`0x2

2.  If you want to get the return value of a function, you can do it as follows.  We’ll use the IOUSBController.h API GetFrameNumber.

    virtual UInt64 		GetFrameNumber( void ) = 0;

We see that this is a abstract method implemented by the subclasses of IOUSBController (mainly the host controller drivers) and that it returns a UInt64, the frame number.  We can then create a dtrace probe that will display this value:

sudo dtrace -n '*:*:*GetFrameNumber*:return { stack(); printf("frameNumber = 0x%x", arg1);}'

which will then give you the following type of output:

  6 297844 _ZN12AppleUSBXHCI14GetFrameNumberEv:return
              AppleUSBXHCI`AppleUSBXHCI::GetFrameNumber()+0x2a7
              AppleUSBAudio`AppleUSBAudioStream::queueOutputFrames()+0x54
              AppleUSBAudio`AppleUSBAudioEngine::clipOutputSamples(void const*, void*, unsigned int, unsigned int, _IOAudioStreamFormat const*, IOAudioStream*)+0x4c
              IOAudioFamily`IOAudioStream::clipOutputSamples(unsigned int, unsigned int)+0xc8
              IOAudioFamily`IOAudioStream::clipIfNecessary()+0x142
              IOAudioFamily`IOAudioStream::processOutputSamples(IOAudioClientBuffer*, unsigned int, unsigned int, bool)+0x5b7
              IOAudioFamily`IOAudioEngineUserClient::performClientOutput(unsigned int, unsigned int, IOAudioClientBufferSet*, unsigned int, unsigned int)+0x24e
              IOAudioFamily`IOAudioEngineUserClient::performClientIO(unsigned int, unsigned int, bool, unsigned int, unsigned int, unsigned int)+0xf7
              kernel`iokit_user_client_trap+0xdf
              kernel`mach_call_munger64+0x182
              kernel`hndl_mach_scall64+0x16
frameNumber = 0x4d9ceb8


Hopefully the above can give you a start on how to further debug your issues.  Another option, if applicable, is to use 10.9.4 and install the debug version of the IOUSBFamily.  I would download that package and keep it — you never know if it will suddenly disappear or not.

Woof,

Nano Urbina
Build Slave
Razz Software
http://www.razzsoftware.com

 _______________________________________________
Do not post admin requests to the list. They will be ignored.
Usb mailing list      (email@hidden)
Help/Unsubscribe/Update your Subscription:

This email sent to email@hidden


References: 
 >Replacement for IOUSBFamily log? (From: Eric Gorouben <email@hidden>)



Visit the Apple Store online or at retail locations.
1-800-MY-APPLE

Contact Apple | Terms of Use | Privacy Policy

Copyright © 2011 Apple Inc. All rights reserved.