1/* 2 * Copyright (c) 2008-2009 Apple Inc. All rights reserved. 3 * 4 * @APPLE_LICENSE_HEADER_START@ 5 * 6 * "Portions Copyright (c) 1999 Apple Inc. All Rights 7 * Reserved. This file contains Original Code and/or Modifications of 8 * Original Code as defined in and that are subject to the Apple Public 9 * Source License Version 1.0 (the 'License'). You may not use this file 10 * except in compliance with the License. Please obtain a copy of the 11 * License at http://www.apple.com/publicsource and read it before using 12 * this file. 13 * 14 * The Original Code and all software distributed under the License are 15 * distributed on an 'AS IS' basis, WITHOUT WARRANTY OF ANY KIND, EITHER 16 * EXPRESS OR IMPLIED, AND APPLE HEREBY DISCLAIMS ALL SUCH WARRANTIES, 17 * INCLUDING WITHOUT LIMITATION, ANY WARRANTIES OF MERCHANTABILITY, 18 * FITNESS FOR A PARTICULAR PURPOSE OR NON-INFRINGEMENT. Please see the 19 * License for the specific language governing rights and limitations 20 * under the License." 21 * 22 * @APPLE_LICENSE_HEADER_END@ 23 */ 24 25/* 26g++ -W -Wall -I/System/Library/Frameworks/System.framework/PrivateHeaders -I/System/Library/Frameworks/Kernel.framework/PrivateHeaders -lutil -DPRIVATE -D__APPLE_PRIVATE -O -arch ppc -arch i386 -arch x86_64 -o UMCLogger UMCLogger.cpp 27*/ 28 29 30//----------------------------------------------------------------------------- 31// Includes 32//----------------------------------------------------------------------------- 33 34#include <errno.h> 35#include <getopt.h> 36#include <signal.h> 37#include <spawn.h> 38#include <stdlib.h> 39#include <stdio.h> 40#include <stdint.h> 41#include <string.h> 42#include <unistd.h> 43#include <libutil.h> 44 45#include <mach/clock_types.h> 46#include <mach/mach_time.h> 47 48#include <sys/types.h> 49#include <sys/param.h> 50#include <sys/sysctl.h> 51#include <sys/time.h> 52#include <sys/wait.h> 53 54#ifndef KERNEL_PRIVATE 55#define KERNEL_PRIVATE 56#include <sys/kdebug.h> 57#undef KERNEL_PRIVATE 58#else 59#include <sys/kdebug.h> 60#endif /*KERNEL_PRIVATE*/ 61 62#include <IOKit/scsi/IOSCSIArchitectureModelFamilyDebugging.h> 63#include <IOKit/scsi/SCSICommandOperationCodes.h> 64 65#include "../IOUSBMassStorageClassTimestamps.h" 66 67#include <IOKit/usb/USB.h> 68 69#define DEBUG 0 70 71//----------------------------------------------------------------------------- 72// Structures 73//----------------------------------------------------------------------------- 74 75typedef struct ReturnCodeSpec 76{ 77 unsigned int returnCode; 78 const char * string; 79} ReturnCodeSpec; 80 81 82//----------------------------------------------------------------------------- 83// Constants 84//----------------------------------------------------------------------------- 85 86enum 87{ 88 89 // Generic USB Storage 0x052D0000 - 0x052D03FF 90 kAbortedTaskCode = UMC_TRACE ( kAbortedTask ), 91 kCompleteSCSICommandCode = UMC_TRACE ( kCompleteSCSICommand ), 92 kNewCommandWhileTerminatingCode = UMC_TRACE ( kNewCommandWhileTerminating ), 93 kLUNConfigurationCompleteCode = UMC_TRACE ( kLUNConfigurationComplete ), 94 kIOUMCStorageCharacDictFoundCode = UMC_TRACE ( kIOUMCStorageCharacDictFound ), 95 kNoProtocolForDeviceCode = UMC_TRACE ( kNoProtocolForDevice ), 96 kIOUSBMassStorageClassStartCode = UMC_TRACE ( kIOUSBMassStorageClassStart ), 97 kIOUSBMassStorageClassStopCode = UMC_TRACE ( kIOUSBMassStorageClassStop ), 98 kAtUSBAddressCode = UMC_TRACE ( kAtUSBAddress ), 99 kMessagedCalledCode = UMC_TRACE ( kMessagedCalled ), 100 kWillTerminateCalledCode = UMC_TRACE ( kWillTerminateCalled ), 101 kDidTerminateCalledCode = UMC_TRACE ( kDidTerminateCalled ), 102 kCDBLog1Code = UMC_TRACE ( kCDBLog1 ), 103 kCDBLog2Code = UMC_TRACE ( kCDBLog2 ), 104 kClearEndPointStallCode = UMC_TRACE ( kClearEndPointStall ), 105 kGetEndPointStatusCode = UMC_TRACE ( kGetEndPointStatus ), 106 kHandlePowerOnUSBResetCode = UMC_TRACE ( kHandlePowerOnUSBReset ), 107 kUSBDeviceResetWhileTerminatingCode = UMC_TRACE ( kUSBDeviceResetWhileTerminating ), 108 kUSBDeviceResetAfterDisconnectCode = UMC_TRACE ( kUSBDeviceResetAfterDisconnect ), 109 kUSBDeviceResetReturnedCode = UMC_TRACE ( kUSBDeviceResetReturned ), 110 kAbortCurrentSCSITaskCode = UMC_TRACE ( kAbortCurrentSCSITask ), 111 kCompletingCommandWithErrorCode = UMC_TRACE ( kCompletingCommandWithError ), 112 kDeviceInformationCode = UMC_TRACE ( kDeviceInformation ), 113 kSuspendPortCode = UMC_TRACE ( kSuspendPort ), 114 kSubclassUseCode = UMC_TRACE ( kSubclassUse ), 115 116 // CBI Specific 0x052D0400 - 0x052D07FF 117 kCBIProtocolDeviceDetectedCode = UMC_TRACE ( kCBIProtocolDeviceDetected ), 118 kCBICommandAlreadyInProgressCode = UMC_TRACE ( kCBICommandAlreadyInProgress ), 119 kCBISendSCSICommandReturnedCode = UMC_TRACE ( kCBISendSCSICommandReturned ), 120 121 // UFI Specific 0x052D0800 - 0x052D0BFF 122 123 // Bulk-Only Specific 0x052D0C00 - 0x052D0FFF 124 kBODeviceDetectedCode = UMC_TRACE ( kBODeviceDetected ), 125 kBOPreferredMaxLUNCode = UMC_TRACE ( kBOPreferredMaxLUN ), 126 kBOGetMaxLUNReturnedCode = UMC_TRACE ( kBOGetMaxLUNReturned ), 127 kBOCommandAlreadyInProgressCode = UMC_TRACE ( kBOCommandAlreadyInProgress ), 128 kBOSendSCSICommandReturnedCode = UMC_TRACE ( kBOSendSCSICommandReturned ), 129 kBOCBWDescriptionCode = UMC_TRACE ( kBOCBWDescription ), 130 kBOCBWBulkOutWriteResultCode = UMC_TRACE ( kBOCBWBulkOutWriteResult ), 131 kBODoubleCompleteionCode = UMC_TRACE ( kBODoubleCompleteion ), 132 kBOCompletionDuringTerminationCode = UMC_TRACE ( kBOCompletionDuringTermination ), 133 kBOCompletionCode = UMC_TRACE ( kBOCompletion ) 134 135}; 136 137 138static const char * kBulkOnlyStateNames[] = { " ", 139 "BulkOnlyCommandSent", 140 "BulkOnlyCheckCBWBulkStall", 141 "BulkOnlyClearCBWBulkStall", 142 "BulkOnlyBulkIOComplete", 143 "BulkOnlyCheckBulkStall", 144 "BulkOnlyClearBulkStall", 145 "BulkOnlyCheckBulkStallPostCSW", 146 "BulkOnlyClearBulkStallPostCSW", 147 "BulkOnlyStatusReceived", 148 "BulkOnlyStatusReceived2ndTime", 149 "BulkOnlyResetCompleted", 150 "BulkOnlyClearBulkInCompleted", 151 "BulkOnlyClearBulkOutCompleted" }; 152 153 154#define kTraceBufferSampleSize 60000 155#define kMicrosecondsPerSecond 1000000 156#define kMicrosecondsPerMillisecond 1000 157#define kFilePathMaxSize 256 158#define kInvalid 0xdeadbeef 159#define kDivisorEntry 0xfeedface 160 161 162//----------------------------------------------------------------------------- 163// Globals 164//----------------------------------------------------------------------------- 165 166int gNumCPUs = 1; 167double gDivisor = 0.0; /* Trace divisor converts to microseconds */ 168kd_buf * gTraceBuffer = NULL; 169boolean_t gTraceEnabled = FALSE; 170boolean_t gSetRemoveFlag = TRUE; 171boolean_t gEnableTraceOnly = FALSE; 172const char * gProgramName = NULL; 173uint32_t gSavedTraceMask = 0; 174boolean_t gHideBusyRejectedCommands = FALSE; 175 176boolean_t gWriteToTraceFile = FALSE; 177boolean_t gReadTraceFile = FALSE; 178FILE * gTraceFileStream = NULL; 179char gTraceFilePath [ kFilePathMaxSize ] = { 0 }; 180 181u_int8_t fullCDB [ 16 ] = { 0 }; 182int64_t current_usecs = 0; 183int64_t prev_usecs = 0; 184int64_t delta_usecs = 0; 185 186 187//----------------------------------------------------------------------------- 188// Prototypes 189//----------------------------------------------------------------------------- 190 191static void 192EnableTraceBuffer ( int val ); 193 194static void 195CollectTrace ( void ); 196 197static void 198CreateTraceOutputFile ( void ); 199 200static void 201ParseTraceFile ( void ); 202 203static void 204ParseKernelTracePoint ( kd_buf inTracePoint ); 205 206static void 207SignalHandler ( int signal ); 208 209static void 210GetDivisor ( void ); 211 212static void 213RegisterSignalHandlers ( void ); 214 215static void 216AllocateTraceBuffer ( void ); 217 218static void 219RemoveTraceBuffer ( void ); 220 221static void 222SetTraceBufferSize ( int nbufs ); 223 224static void 225Quit ( const char * s ); 226 227static void 228InitializeTraceBuffer ( void ); 229 230static void 231ParseArguments ( int argc, const char * argv[] ); 232 233static void 234PrintUsage ( void ); 235 236static void 237PrintSCSICommand ( void ); 238 239static void 240PrintTimeStamp ( void ); 241 242static void 243LoadUSBMassStorageExtension ( void ); 244 245static const char * 246StringFromReturnCode ( unsigned int returnCode ); 247 248void 249ProcessSubclassTracePoint ( kd_buf inTracePoint ); 250 251void 252ProcessAppleUSBCardReaderUMCSubclassTracePoint ( kd_buf inTracePoint, UInt32 intSubclassCode ); 253 254void 255ProcessAppleUSBODDSubclassTracePoint ( kd_buf inTracePoint, UInt32 intSubclassCode ); 256 257 258//----------------------------------------------------------------------------- 259// Main 260//----------------------------------------------------------------------------- 261 262int 263main ( int argc, const char * argv[] ) 264{ 265 266 USBSysctlArgs args; 267 int error; 268 269 gProgramName = argv[0]; 270 271 if ( reexec_to_match_kernel ( ) != 0 ) 272 { 273 274 fprintf ( stderr, "Could not re-execute to match kernel architecture, errno = %d\n", errno ); 275 exit ( 1 ); 276 277 } 278 279 if ( geteuid ( ) != 0 ) 280 { 281 282 fprintf ( stderr, "'%s' must be run as root...\n", gProgramName ); 283 exit ( 1 ); 284 285 } 286 287 // Get program arguments. 288 ParseArguments ( argc, argv ); 289 290 bzero ( &args, sizeof ( args ) ); 291 292 args.type = kUSBTypeDebug; 293 args.operation = kUSBOperationGetFlags; 294 295 error = sysctlbyname ( USBMASS_SYSCTL, NULL, NULL, &args, sizeof ( args ) ); 296 if ( error != 0 ) 297 { 298 fprintf ( stderr, "sysctlbyname failed to get old umctrace flags\n" ); 299 } 300 301 args.type = kUSBTypeDebug; 302 args.operation = kUSBOperationSetFlags; 303 args.debugFlags = 1; 304 305 error = sysctlbyname ( USBMASS_SYSCTL, NULL, NULL, &args, sizeof ( args ) ); 306 if ( error != 0 ) 307 { 308 309 LoadUSBMassStorageExtension ( ); 310 311 error = sysctlbyname ( USBMASS_SYSCTL, NULL, NULL, &args, sizeof ( args ) ); 312 if ( error != 0 ) 313 { 314 fprintf ( stderr, "sysctlbyname failed to set new umctrace flags\n" ); 315 } 316 317 } 318 319#if DEBUG 320 printf ( "gSavedTraceMask = 0x%08X\n", gSavedTraceMask ); 321 printf ( "gPrintfMask = 0x%08X\n", gPrintfMask ); 322 printf ( "gVerbose = %s\n", gVerbose == TRUE ? "True" : "False" ); 323 fflush ( stdout ); 324#endif 325 326 // Set up signal handlers. 327 RegisterSignalHandlers ( ); 328 329 // Allocate trace buffer. 330 AllocateTraceBuffer ( ); 331 332 // Remove the trace buffer. 333 RemoveTraceBuffer ( ); 334 335 // Set the new trace buffer size. 336 SetTraceBufferSize ( kTraceBufferSampleSize ); 337 338 // Initialize the trace buffer. 339 InitializeTraceBuffer ( ); 340 341 // Enable the trace buffer. 342 EnableTraceBuffer ( 1 ); 343 344 // Get the clock divisor. 345 GetDivisor ( ); 346 347 if ( gWriteToTraceFile == TRUE ) 348 { 349 CreateTraceOutputFile ( ); 350 } 351 352 // Does the user only want the trace points enabled and no logging? 353 if ( gEnableTraceOnly == FALSE ) 354 { 355 356 if ( gReadTraceFile == FALSE ) 357 { 358 359 // No, they want logging. Start main loop. 360 while ( 1 ) 361 { 362 363 usleep ( 20 * kMicrosecondsPerMillisecond ); 364 CollectTrace ( ); 365 366 } 367 368 } 369 370 else 371 { 372 373 ParseTraceFile ( ); 374 375 } 376 377 } 378 379 return 0; 380 381} 382 383 384//----------------------------------------------------------------------------- 385// PrintUsage 386//----------------------------------------------------------------------------- 387 388static void 389PrintUsage ( void ) 390{ 391 392 printf ( "\n" ); 393 394 printf ( "Usage: %s\n\n", gProgramName ); 395 printf ( "\t-h help\n" ); 396 printf ( "\t-b hide rejected SCSI tasks\n" ); 397 printf ( "\t-d disable\n" ); 398 printf ( "\t-f <file_path> write traces out directly to a file.\n" ); 399 printf ( "\t-r <file_path> parses trace file\n" ); 400 401 printf ( "\n" ); 402 403 exit ( 0 ); 404 405} 406 407 408//----------------------------------------------------------------------------- 409// ParseArguments 410//----------------------------------------------------------------------------- 411 412static void 413ParseArguments ( int argc, const char * argv[] ) 414{ 415 416 int c; 417 struct option long_options[] = 418 { 419 { "disable", no_argument, 0, 'd' }, 420 { "busy", no_argument, 0, 'b' }, 421 { "file", required_argument, 0, 'f' }, 422 { "read", required_argument, 0, 'r' }, 423 { "help", no_argument, 0, 'h' }, 424 { 0, 0, 0, 0 } 425 }; 426 427 // If no args specified, enable all logging... 428 if ( argc == 1 ) 429 { 430 return; 431 } 432 433 while ( ( c = getopt_long ( argc, ( char * const * ) argv , "dbf:r:h?", long_options, NULL ) ) != -1 ) 434 { 435 436 switch ( c ) 437 { 438 439 case 'd': 440 { 441 442 gSavedTraceMask = 0; 443 gSetRemoveFlag = FALSE; 444 Quit ( "Quit via user-specified trace disable\n" ); 445 446 } 447 break; 448 449 case 'b': 450 { 451 452 gHideBusyRejectedCommands = TRUE; 453 break; 454 455 } 456 457 case 'f': 458 { 459 460 gWriteToTraceFile = TRUE; 461 462 if ( optarg != NULL ) 463 { 464 465 if ( strlcpy ( gTraceFilePath, optarg, sizeof ( gTraceFilePath ) ) >= sizeof ( gTraceFilePath ) ) 466 { 467 Quit ( "The path length of raw file is too long\n" ); 468 } 469 470 } 471 472 else 473 { 474 Quit ( "No file specified with -f argument\n"); 475 } 476 477 } 478 break; 479 480 case 'r': 481 { 482 483 gReadTraceFile = TRUE; 484 485 if ( optarg != NULL ) 486 { 487 488 if ( strlcpy ( gTraceFilePath, optarg, sizeof ( gTraceFilePath ) ) >= sizeof ( gTraceFilePath ) ) 489 { 490 Quit ( "The path length of raw file is too long\n" ); 491 } 492 493 } 494 495 else 496 { 497 Quit ( "No file specified with -r argument\n"); 498 } 499 500 } 501 break; 502 503 case 'h': 504 { 505 PrintUsage ( ); 506 } 507 break; 508 509 default: 510 { 511 512 PrintUsage ( ); 513 Quit ( "Invalid usage\n"); 514 515 } 516 break; 517 518 } 519 520 } 521 522} 523 524 525//----------------------------------------------------------------------------- 526// RegisterSignalHandlers 527//----------------------------------------------------------------------------- 528 529static void 530RegisterSignalHandlers ( void ) 531{ 532 533 signal ( SIGINT, SignalHandler ); 534 signal ( SIGQUIT, SignalHandler ); 535 signal ( SIGHUP, SignalHandler ); 536 signal ( SIGTERM, SignalHandler ); 537 538} 539 540 541//----------------------------------------------------------------------------- 542// AllocateTraceBuffer 543//----------------------------------------------------------------------------- 544 545static void 546AllocateTraceBuffer ( void ) 547{ 548 549 size_t len; 550 int mib[3]; 551 552 // grab the number of cpus 553 mib[0] = CTL_HW; 554 mib[1] = HW_NCPU; 555 mib[2] = 0; 556 557 len = sizeof ( gNumCPUs ); 558 559 sysctl ( mib, 2, &gNumCPUs, &len, NULL, 0 ); 560 561 gTraceBuffer = ( kd_buf * ) malloc ( gNumCPUs * kTraceBufferSampleSize * sizeof ( kd_buf ) ); 562 if ( gTraceBuffer == NULL ) 563 { 564 Quit ( "Can't allocate memory for tracing info\n" ); 565 } 566 567} 568 569 570//----------------------------------------------------------------------------- 571// SignalHandler 572//----------------------------------------------------------------------------- 573 574static void 575SignalHandler ( int signal ) 576{ 577 578#pragma unused ( signal ) 579 580 EnableTraceBuffer ( 0 ); 581 RemoveTraceBuffer ( ); 582 exit ( 0 ); 583 584} 585 586 587//----------------------------------------------------------------------------- 588// EnableTraceBuffer 589//----------------------------------------------------------------------------- 590 591static void 592EnableTraceBuffer ( int val ) 593{ 594 595 int mib[6]; 596 size_t needed; 597 598 mib[0] = CTL_KERN; 599 mib[1] = KERN_KDEBUG; 600 mib[2] = KERN_KDENABLE; /* protocol */ 601 mib[3] = val; 602 mib[4] = 0; 603 mib[5] = 0; /* no flags */ 604 605 if ( sysctl ( mib, 4, NULL, &needed, NULL, 0 ) < 0 ) 606 Quit ( "trace facility failure, KERN_KDENABLE\n" ); 607 608 if ( val ) 609 gTraceEnabled = TRUE; 610 else 611 gTraceEnabled = FALSE; 612 613} 614 615 616//----------------------------------------------------------------------------- 617// SetTraceBufferSize 618//----------------------------------------------------------------------------- 619 620static void 621SetTraceBufferSize ( int nbufs ) 622{ 623 624 int mib[6]; 625 size_t needed; 626 627 mib[0] = CTL_KERN; 628 mib[1] = KERN_KDEBUG; 629 mib[2] = KERN_KDSETBUF; 630 mib[3] = nbufs; 631 mib[4] = 0; 632 mib[5] = 0; /* no flags */ 633 634 if ( sysctl ( mib, 4, NULL, &needed, NULL, 0 ) < 0 ) 635 Quit ( "trace facility failure, KERN_KDSETBUF\n" ); 636 637 mib[0] = CTL_KERN; 638 mib[1] = KERN_KDEBUG; 639 mib[2] = KERN_KDSETUP; 640 mib[3] = 0; 641 mib[4] = 0; 642 mib[5] = 0; /* no flags */ 643 644 if ( sysctl ( mib, 3, NULL, &needed, NULL, 0 ) < 0 ) 645 Quit ( "trace facility failure, KERN_KDSETUP\n" ); 646 647} 648 649 650//----------------------------------------------------------------------------- 651// GetTraceBufferInfo 652//----------------------------------------------------------------------------- 653 654static void 655GetTraceBufferInfo ( kbufinfo_t * val ) 656{ 657 658 int mib[6]; 659 size_t needed; 660 661 needed = sizeof ( *val ); 662 663 mib[0] = CTL_KERN; 664 mib[1] = KERN_KDEBUG; 665 mib[2] = KERN_KDGETBUF; 666 mib[3] = 0; 667 mib[4] = 0; 668 mib[5] = 0; /* no flags */ 669 670 if ( sysctl ( mib, 3, val, &needed, 0, 0 ) < 0 ) 671 Quit ( "trace facility failure, KERN_KDGETBUF\n" ); 672 673} 674 675 676//----------------------------------------------------------------------------- 677// RemoveTraceBuffer 678//----------------------------------------------------------------------------- 679 680static void 681RemoveTraceBuffer ( void ) 682{ 683 684 int mib[6]; 685 size_t needed; 686 687 errno = 0; 688 689 mib[0] = CTL_KERN; 690 mib[1] = KERN_KDEBUG; 691 mib[2] = KERN_KDREMOVE; /* protocol */ 692 mib[3] = 0; 693 mib[4] = 0; 694 mib[5] = 0; /* no flags */ 695 696 if ( sysctl ( mib, 3, NULL, &needed, NULL, 0 ) < 0 ) 697 { 698 699 gSetRemoveFlag = FALSE; 700 701 if ( errno == EBUSY ) 702 Quit ( "The trace facility is currently in use...\n fs_usage, sc_usage, and latency use this feature.\n\n" ); 703 704 else 705 Quit ( "Trace facility failure, KERN_KDREMOVE\n" ); 706 707 } 708 709} 710 711 712//----------------------------------------------------------------------------- 713// InitializeTraceBuffer 714//----------------------------------------------------------------------------- 715 716static void 717InitializeTraceBuffer ( void ) 718{ 719 720 int mib[6]; 721 size_t needed; 722 kd_regtype kr; 723 724 kr.type = KDBG_RANGETYPE; 725 kr.value1 = 0; 726 kr.value2 = -1; 727 728 needed = sizeof ( kd_regtype ); 729 730 mib[0] = CTL_KERN; 731 mib[1] = KERN_KDEBUG; 732 mib[2] = KERN_KDSETREG; 733 mib[3] = 0; 734 mib[4] = 0; 735 mib[5] = 0; /* no flags */ 736 737 if ( sysctl ( mib, 3, &kr, &needed, NULL, 0 ) < 0 ) 738 Quit ( "trace facility failure, KERN_KDSETREG\n" ); 739 740 mib[0] = CTL_KERN; 741 mib[1] = KERN_KDEBUG; 742 mib[2] = KERN_KDSETUP; 743 mib[3] = 0; 744 mib[4] = 0; 745 mib[5] = 0; /* no flags */ 746 747 if ( sysctl ( mib, 3, NULL, &needed, NULL, 0 ) < 0 ) 748 Quit ( "trace facility failure, KERN_KDSETUP\n" ); 749 750 kr.type = KDBG_SUBCLSTYPE; 751 kr.value1 = DBG_IOKIT; 752 kr.value2 = DBG_IOSAM; 753 754 needed = sizeof ( kd_regtype ); 755 756 mib[0] = CTL_KERN; 757 mib[1] = KERN_KDEBUG; 758 mib[2] = KERN_KDSETREG; 759 mib[3] = 0; 760 mib[4] = 0; 761 mib[5] = 0; 762 763 if ( sysctl ( mib, 3, &kr, &needed, NULL, 0 ) < 0 ) 764 Quit ( "trace facility failure, KERN_KDSETREG (subclstype)\n" ); 765 766} 767 768 769//----------------------------------------------------------------------------- 770// PrintSCSICommand 771//----------------------------------------------------------------------------- 772 773static void 774PrintSCSICommand ( void ) 775{ 776 777 switch ( fullCDB [0] ) 778 { 779 780 case kSCSICmd_TEST_UNIT_READY: 781 { 782 783 printf ( " kSCSICmd_TEST_UNIT_READY\n" ); 784 785 } 786 break; 787 788 case kSCSICmd_REQUEST_SENSE: 789 { 790 791 printf ( " kSCSICmd_REQUEST_SENSE\n" ); 792 793 } 794 break; 795 796 case kSCSICmd_READ_10: 797 { 798 799 u_int32_t LOGICAL_BLOCK_ADDRESS = 0; 800 u_int16_t TRANSFER_LENGTH = 0; 801 802 LOGICAL_BLOCK_ADDRESS = fullCDB [2]; 803 LOGICAL_BLOCK_ADDRESS <<= 8; 804 LOGICAL_BLOCK_ADDRESS |= fullCDB [3]; 805 LOGICAL_BLOCK_ADDRESS <<= 8; 806 LOGICAL_BLOCK_ADDRESS |= fullCDB [4]; 807 LOGICAL_BLOCK_ADDRESS <<= 8; 808 LOGICAL_BLOCK_ADDRESS |= fullCDB [5]; 809 810 TRANSFER_LENGTH = fullCDB [7]; 811 TRANSFER_LENGTH <<= 8; 812 TRANSFER_LENGTH |= fullCDB [8]; 813 814 printf ( "kSCSICmd_READ_10, LBA = %p, length = %p\n", ( void * ) LOGICAL_BLOCK_ADDRESS, ( void * ) TRANSFER_LENGTH ); 815 816 } 817 break; 818 819 case kSCSICmd_WRITE_10: 820 { 821 822 u_int32_t LOGICAL_BLOCK_ADDRESS = 0; 823 u_int16_t TRANSFER_LENGTH = 0; 824 825 LOGICAL_BLOCK_ADDRESS = fullCDB [2]; 826 LOGICAL_BLOCK_ADDRESS <<= 8; 827 LOGICAL_BLOCK_ADDRESS |= fullCDB [3]; 828 LOGICAL_BLOCK_ADDRESS <<= 8; 829 LOGICAL_BLOCK_ADDRESS |= fullCDB [4]; 830 LOGICAL_BLOCK_ADDRESS <<= 8; 831 LOGICAL_BLOCK_ADDRESS |= fullCDB [5]; 832 833 TRANSFER_LENGTH = fullCDB [7]; 834 TRANSFER_LENGTH <<= 8; 835 TRANSFER_LENGTH |= fullCDB [8]; 836 837 printf ( "kSCSICmd_WRITE_10, LBA = %p, length = %p\n", ( void * ) LOGICAL_BLOCK_ADDRESS, ( void * ) TRANSFER_LENGTH ); 838 839 } 840 break; 841 842 default: 843 { 844 printf ( "This command has not yet been decoded\n" ); 845 } 846 break; 847 848 } 849 850} 851 852 853//----------------------------------------------------------------------------- 854// PrintTimeStamp 855//----------------------------------------------------------------------------- 856 857static void 858PrintTimeStamp ( void ) 859{ 860 861 time_t currentTime = time ( NULL ); 862 863 if ( prev_usecs == 0 ) 864 { 865 delta_usecs = 0; 866 } 867 else 868 { 869 delta_usecs = current_usecs - prev_usecs; 870 } 871 872 prev_usecs = current_usecs; 873 874/* 875 876 if ( delta_usecs > (100 * kMicrosecondsPerMillisecond ) 877 { 878 printf ( "*** " ); 879 } 880 else 881 { 882 printf ( " " ); 883 } 884 885*/ 886 887 printf ( "%-8.8s [%lld][%10lld us]", &( ctime ( ¤tTime )[11] ), current_usecs, delta_usecs ); 888 889} 890 891//----------------------------------------------------------------------------- 892// CollectTrace 893//----------------------------------------------------------------------------- 894 895static void 896CollectTrace ( void ) 897{ 898 899 int mib[6]; 900 int index; 901 int count; 902 size_t needed; 903 kbufinfo_t bufinfo = { 0, 0, 0, 0, 0 }; 904 905 /* Get kernel buffer information */ 906 GetTraceBufferInfo ( &bufinfo ); 907 908 needed = bufinfo.nkdbufs * sizeof ( kd_buf ); 909 mib[0] = CTL_KERN; 910 mib[1] = KERN_KDEBUG; 911 mib[2] = KERN_KDREADTR; 912 mib[3] = 0; 913 mib[4] = 0; 914 mib[5] = 0; /* no flags */ 915 916 if ( sysctl ( mib, 3, gTraceBuffer, &needed, NULL, 0 ) < 0 ) 917 Quit ( "trace facility failure, KERN_KDREADTR\n" ); 918 919 count = needed; 920 921 if ( bufinfo.flags & KDBG_WRAPPED ) 922 { 923 924 EnableTraceBuffer ( 0 ); 925 EnableTraceBuffer ( 1 ); 926 927 } 928 929 for ( index = 0; index < count; index++ ) 930 { 931 932 // Print trace data to stdout. 933 if ( gWriteToTraceFile == FALSE ) 934 { 935 936 int debugID; 937 int type; 938 939 debugID = gTraceBuffer[index].debugid; 940 type = debugID & ~( DBG_FUNC_START | DBG_FUNC_END ); 941 942 //printf ("type = 0x%x\n", UMC_TRACE ( 0x0 ), UMC_TRACE ( 0xFFF ) ); 943 ParseKernelTracePoint ( gTraceBuffer [ index ] ); 944 } 945 946 // Save trace point data to a file. 947 else 948 { 949 950 int debugID; 951 int type; 952 953 debugID = gTraceBuffer[index].debugid; 954 type = debugID & ~( DBG_FUNC_START | DBG_FUNC_END ); 955 956 if ( ( type >= 0x05278800 ) && ( type <= 0x05278BFC ) ) 957 { 958 959 fwrite ( ( const void * ) & ( gTraceBuffer [ index ] ), 960 sizeof ( kd_buf ), 961 1, 962 gTraceFileStream ); 963 964 fflush ( gTraceFileStream ); 965 966 } 967 968 } 969 970 } 971 972 fflush ( 0 ); 973 974} 975 976 977 978 979//----------------------------------------------------------------------------- 980// CreateTraceOutputFile 981//----------------------------------------------------------------------------- 982 983static void 984CreateTraceOutputFile ( void ) 985{ 986 987 char timestring [ 30 ]; 988 time_t currentTime = time ( NULL ); 989 990 // Did the user not supply a preferred file path? 991 if ( gTraceFilePath[0] == 0 ) 992 { 993 994 strftime ( timestring, 30, "./sdxclogger-%y%d%m%H%M%S.bin", localtime ( ¤tTime ) ); 995 996 if ( strlcpy ( gTraceFilePath, timestring, sizeof ( gTraceFilePath ) ) >= sizeof ( gTraceFilePath ) ) 997 { 998 Quit ( "The path length of raw file is too long\n" ); 999 } 1000 1001 } 1002 1003 gTraceFileStream = fopen ( gTraceFilePath, "w+" ); 1004 1005} 1006 1007 1008//----------------------------------------------------------------------------- 1009// ParseTraceFile 1010//----------------------------------------------------------------------------- 1011 1012static void 1013ParseTraceFile ( ) 1014{ 1015 1016 FILE * traceFile; 1017 1018 traceFile = fopen ( gTraceFilePath, "r" ); 1019 kd_buf kp; 1020 bzero( &kp, sizeof ( kd_buf ) ); 1021 1022 if ( traceFile ) 1023 { 1024 1025 while ( fread ( &kp, sizeof ( kd_buf ), 1, traceFile ) ) 1026 { 1027 1028 kd_buf tracepoint; 1029 bzero ( &tracepoint, sizeof ( kd_buf ) ); 1030 1031 if ( kp.debugid == kInvalid ) 1032 { 1033 1034 printf ( "Found an invalid entry in raw file.\n" ); 1035 continue; 1036 1037 } 1038 1039 if ( kp.debugid == kDivisorEntry ) 1040 { 1041 1042 gDivisor = ( double )( kp.timestamp ); 1043 printf ( "Found divisor %f as 0x%llx\n", gDivisor, kp.timestamp ); 1044 1045 } 1046 else 1047 { 1048 1049 // send tracepoint to be processed 1050 ParseKernelTracePoint ( kp ); 1051 1052 } 1053 1054 } 1055 1056 fclose ( traceFile ); 1057 1058 } 1059 1060 else 1061 { 1062 Quit ( "Could not open specified trace file :(\n" ); 1063 } 1064 1065} 1066 1067 1068//----------------------------------------------------------------------------- 1069// StringFromReturnCode 1070//----------------------------------------------------------------------------- 1071 1072static void 1073ParseKernelTracePoint ( kd_buf inTracePoint ) 1074{ 1075 1076 1077 int debugID; 1078 int type; 1079 uint64_t now; 1080 const char * errorString; 1081 1082 debugID = inTracePoint.debugid; 1083 type = debugID & ~( DBG_FUNC_START | DBG_FUNC_END ); 1084 1085 now = inTracePoint.timestamp & KDBG_TIMESTAMP_MASK; 1086 current_usecs = ( int64_t )( now / gDivisor ); 1087 1088 1089 1090 if ( ( type >= 0x05278800 ) && ( type <= 0x05278BFC ) && ( type != kCDBLog2Code ) ) 1091 { 1092 PrintTimeStamp ( ); 1093 } 1094 1095 switch ( type ) 1096 { 1097 1098#pragma mark - 1099#pragma mark *** Generic UMC Codes *** 1100#pragma mark - 1101 1102 case kAbortedTaskCode: 1103 { 1104 printf ( "[%10p] Task %p Aborted!!!\n", ( void * ) inTracePoint.arg1, ( void * ) inTracePoint.arg2 ); 1105 } 1106 break; 1107 1108 case kAbortCurrentSCSITaskCode: 1109 { 1110 printf ( "[%10p] Aborted currentTask %p DeviceAttached = %d ConsecutiveResetCount = %d\n", 1111 ( void * ) inTracePoint.arg1, ( void * ) inTracePoint.arg2, 1112 ( int ) inTracePoint.arg3, ( int ) inTracePoint.arg4 ); 1113 } 1114 break; 1115 1116 case kCompleteSCSICommandCode: 1117 { 1118 1119 printf ( "[%10p] Task %p Completed with serviceResponse = %d taskStatus = 0x%x\n", 1120 ( void * ) inTracePoint.arg1, ( void * ) inTracePoint.arg2, 1121 ( int ) inTracePoint.arg3, ( int ) inTracePoint.arg4 ); 1122 PrintTimeStamp ( ); 1123 printf ( "[%10p] -------------------------------------------------\n", ( void * ) inTracePoint.arg1 ); 1124 1125 } 1126 break; 1127 1128 case kCompletingCommandWithErrorCode: 1129 { 1130 printf ( "[%10p] !!!!! Hark !!!!! Completing command with an ERROR status!\n", ( void * ) inTracePoint.arg1 ); 1131 } 1132 break; 1133 1134 case kLUNConfigurationCompleteCode: 1135 { 1136 printf ( "[%10p] MaxLUN = %u\n", ( void * ) inTracePoint.arg1, ( unsigned int ) inTracePoint.arg2 ); 1137 } 1138 break; 1139 1140 case kNewCommandWhileTerminatingCode: 1141 { 1142 printf ( "[%10p] Task = %p received while terminating!!!\n", ( void * ) inTracePoint.arg1, ( void * ) inTracePoint.arg2 ); 1143 } 1144 break; 1145 1146 case kIOUMCStorageCharacDictFoundCode: 1147 { 1148 printf ( "[%10p] This device has a USB Characteristics Dictionary\n", ( void * ) inTracePoint.arg1 ); 1149 } 1150 break; 1151 1152 case kNoProtocolForDeviceCode: 1153 { 1154 printf ( "[%10p] !!! NO USB TRANSPORT PROTOCOL FOR THIS DEVICE !!!\n", ( void * ) inTracePoint.arg1 ); 1155 } 1156 break; 1157 1158 case kIOUSBMassStorageClassStartCode: 1159 { 1160 printf ( "[%10p] Starting up!\n", ( void * ) inTracePoint.arg1 ); 1161 } 1162 break; 1163 1164 case kIOUSBMassStorageClassStopCode: 1165 { 1166 printf ( "[%10p] Stopping!\n", ( void * ) inTracePoint.arg1 ); 1167 } 1168 break; 1169 1170 case kAtUSBAddressCode: 1171 { 1172 printf ( "[%10p] @ USB Address: %u\n", ( void * ) inTracePoint.arg1, ( unsigned int ) inTracePoint.arg2 ); 1173 } 1174 break; 1175 1176 case kMessagedCalledCode: 1177 { 1178 printf ( "[%10p] Message : %x received\n", ( void * ) inTracePoint.arg1, ( unsigned int ) inTracePoint.arg2 ); 1179 PrintTimeStamp ( ); 1180 printf ( "[%10p] -------------------------------------------------\n", ( void * ) inTracePoint.arg1 ); 1181 } 1182 break; 1183 1184 case kWillTerminateCalledCode: 1185 { 1186 printf ( "[%10p] willTerminate called, CurrentInterface=%p, isInactive=%u\n", 1187 ( void * ) inTracePoint.arg1, ( void * ) inTracePoint.arg2, ( unsigned int ) inTracePoint.arg3 ); 1188 } 1189 break; 1190 1191 case kDidTerminateCalledCode: 1192 { 1193 printf ( "[%10p] didTerminate called, fTerminationDeferred=%u\n", 1194 ( void * ) inTracePoint.arg1, ( unsigned int ) inTracePoint.arg2 ); 1195 } 1196 break; 1197 1198 case kCDBLog1Code: 1199 { 1200 1201 UInt8 * cdbData; 1202 unsigned int i; 1203 1204 printf ( "[%10p] Request %p\n", ( void * ) inTracePoint.arg1, ( void * ) inTracePoint.arg2 ); 1205 PrintTimeStamp ( ); 1206 printf ( "[%10p] ", ( void * ) inTracePoint.arg1 ); 1207 1208 cdbData = ( UInt8 * ) &inTracePoint.arg3; 1209 1210 for ( i = 0; i < 4; i++ ) 1211 { 1212 fullCDB [i] = cdbData[i]; 1213 printf ( "0x%02X : ", cdbData[i] ); 1214 } 1215 1216 cdbData = ( UInt8 * ) &inTracePoint.arg4; 1217 1218 for ( i = 0; i < 4; i++ ) 1219 { 1220 fullCDB [i+4] = cdbData[i]; 1221 printf ( "0x%02X : ", cdbData[i] ); 1222 } 1223 1224 } 1225 break; 1226 1227 case kCDBLog2Code: 1228 { 1229 1230 UInt8 * cdbData; 1231 unsigned int i; 1232 1233 cdbData = ( UInt8 * ) &inTracePoint.arg3; 1234 1235 for ( i = 0; i < 4; i++ ) 1236 { 1237 fullCDB [i+8] = cdbData[i]; 1238 printf ( "0x%02X : ", cdbData[i] ); 1239 } 1240 1241 cdbData = ( UInt8 * ) &inTracePoint.arg4; 1242 1243 for ( i = 0; i < 3; i++ ) 1244 { 1245 fullCDB [i+12] = cdbData[i]; 1246 printf ( "0x%02X : ", cdbData[i] ); 1247 } 1248 1249 fullCDB [i+12] = cdbData[i]; 1250 printf ( "0x%02X\n", cdbData[i] ); 1251 1252 PrintTimeStamp ( ); 1253 printf ( "[%10p] ", ( void * ) inTracePoint.arg1 ); 1254 PrintSCSICommand ( ); 1255 1256 } 1257 break; 1258 1259 case kClearEndPointStallCode: 1260 { 1261 1262 errorString = StringFromReturnCode ( inTracePoint.arg2 ); 1263 printf ( "[%10p] ClearFeatureEndpointStall status=%s (0x%x), endpoint=%u\n", 1264 ( void * ) inTracePoint.arg1, errorString, ( unsigned int ) inTracePoint.arg2, ( unsigned int ) inTracePoint.arg3 ); 1265 1266 } 1267 break; 1268 1269 case kGetEndPointStatusCode: 1270 { 1271 1272 errorString = StringFromReturnCode ( inTracePoint.arg2 ); 1273 printf ( "[%10p] GetEndpointStatus status=%s (0x%x), endpoint=%u\n", 1274 ( void * ) inTracePoint.arg1, errorString, ( unsigned int ) inTracePoint.arg2, ( unsigned int ) inTracePoint.arg3 ); 1275 1276 } 1277 break; 1278 1279 case kHandlePowerOnUSBResetCode: 1280 { 1281 1282 printf ( "[%10p] USB Device Reset on WAKE from SLEEP\n", ( void * ) inTracePoint.arg1 ); 1283 1284 } 1285 break; 1286 1287 case kUSBDeviceResetWhileTerminatingCode: 1288 { 1289 1290 printf ( "[%10p] Termination started before device reset could be initiated! fTerminating=%u, isInactive=%u\n", 1291 ( void * ) inTracePoint.arg1, ( unsigned int ) inTracePoint.arg2, ( unsigned int ) inTracePoint.arg3 ); 1292 1293 } 1294 break; 1295 1296 case kUSBDeviceResetAfterDisconnectCode: 1297 { 1298 1299 printf ( "[%10p] Device reset was attempted after the device had been disconnected\n", ( void * ) inTracePoint.arg1 ); 1300 1301 } 1302 break; 1303 1304 case kUSBDeviceResetReturnedCode: 1305 { 1306 1307 printf ( "[%10p] DeviceReset returned: 0x%08x\n", ( void * ) inTracePoint.arg1, ( unsigned int ) inTracePoint.arg2 ); 1308 1309 } 1310 break; 1311 1312 case kDeviceInformationCode: 1313 { 1314 errorString = StringFromReturnCode ( inTracePoint.arg2 ); 1315 printf ( "[%10p] Device Information status=%s DeviceInformation=0x%x\n", ( void * ) inTracePoint.arg1, 1316 errorString, ( int ) inTracePoint.arg3 ); 1317 } 1318 break; 1319 1320 case kSuspendPortCode: 1321 { 1322 1323 errorString = StringFromReturnCode ( inTracePoint.arg2 ); 1324 if ( inTracePoint.arg3 == 0 ) 1325 { 1326 printf ( "[%10p] Suspend Port (RESUME) returned status=%s\n", ( void * ) inTracePoint.arg1, errorString ); 1327 } 1328 1329 else 1330 { 1331 printf ( "[%10p] Suspend Port (SUSPEND) returned status=%s\n", ( void * ) inTracePoint.arg1, errorString ); 1332 } 1333 1334 } 1335 break; 1336 1337 case kSubclassUseCode: 1338 { 1339 1340 // This is special code that we let our subclasses use. We have a helper function to handle these. 1341 ProcessSubclassTracePoint ( inTracePoint ); 1342 1343 } 1344 break; 1345 1346#pragma mark - 1347#pragma mark *** Control Bulk Interrupt ( CBI ) Codess *** 1348#pragma mark - 1349 1350 case kCBIProtocolDeviceDetectedCode: 1351 { 1352 1353 printf ( "[%10p] CBI transport protocol device\n", ( void * ) inTracePoint.arg1 ); 1354 1355 } 1356 break; 1357 1358 case kCBICommandAlreadyInProgressCode: 1359 { 1360 1361 if ( gHideBusyRejectedCommands == FALSE ) 1362 { 1363 1364 printf ( "[%10p] CBI - Unable to accept task %p, still working on previous command\n", 1365 ( void * ) inTracePoint.arg1, ( void * ) inTracePoint.arg2 ); 1366 1367 } 1368 1369 } 1370 break; 1371 1372 case kCBISendSCSICommandReturnedCode: 1373 { 1374 1375 errorString = StringFromReturnCode ( inTracePoint.arg3 ); 1376 printf ( "[%10p] CBI - SCSI Task %p was sent with status %s (0x%x)\n", 1377 ( void * ) inTracePoint.arg1, ( void * ) inTracePoint.arg2, errorString, ( unsigned int ) inTracePoint.arg3 ); 1378 1379 } 1380 break; 1381 1382#pragma mark - 1383#pragma mark *** Bulk-Only Protocol Codes *** 1384#pragma mark - 1385 1386 case kBODeviceDetectedCode: 1387 { 1388 1389 printf ( "[%10p] BULK-ONLY transport protocol device\n", ( void * ) inTracePoint.arg1 ); 1390 1391 } 1392 break; 1393 1394 case kBOCommandAlreadyInProgressCode: 1395 { 1396 1397 if ( gHideBusyRejectedCommands == FALSE ) 1398 { 1399 1400 printf ( "[%10p] B0 - Unable to accept task %p, still working on previous request\n", 1401 ( void * ) inTracePoint.arg1, ( void * ) inTracePoint.arg2 ); 1402 1403 } 1404 1405 } 1406 break; 1407 1408 case kBOSendSCSICommandReturnedCode: 1409 { 1410 1411 errorString = StringFromReturnCode ( inTracePoint.arg3 ); 1412 printf ( "[%10p] BO - SCSI Task %p was sent with status %s (0x%x)\n", 1413 ( void * ) inTracePoint.arg1, ( void * ) inTracePoint.arg2, errorString, ( unsigned int ) inTracePoint.arg3 ); 1414 1415 } 1416 break; 1417 1418 case kBOPreferredMaxLUNCode: 1419 { 1420 1421 printf ( "[%10p] BO - Preferred MaxLUN: %d\n", 1422 ( void * ) inTracePoint.arg1, (int) inTracePoint.arg2 ); 1423 1424 } 1425 break; 1426 1427 case kBOGetMaxLUNReturnedCode: 1428 { 1429 1430 errorString = StringFromReturnCode ( inTracePoint.arg2 ); 1431 printf ( "[%10p] BO - GetMaxLUN returned: %s (0x%x), triedReset=%u, MaxLun: %d\n", 1432 ( void * ) inTracePoint.arg1, errorString, ( unsigned int ) inTracePoint.arg2, ( unsigned int ) inTracePoint.arg4, ( unsigned int ) inTracePoint.arg3 ); 1433 1434 } 1435 break; 1436 1437 case kBOCBWDescriptionCode: 1438 { 1439 1440 printf ( "[%10p] BO - Request %p, LUN: %u, CBW Tag: %u (0x%x)\n", 1441 ( void * ) inTracePoint.arg1, ( void * ) inTracePoint.arg2, ( unsigned int ) inTracePoint.arg3, ( unsigned int ) inTracePoint.arg4, ( unsigned int ) inTracePoint.arg4 ); 1442 1443 } 1444 break; 1445 1446 case kBOCBWBulkOutWriteResultCode: 1447 { 1448 1449 errorString = StringFromReturnCode ( inTracePoint.arg2 ); 1450 printf ( "[%10p] BO - Request %p, LUN: %u, Bulk-Out Write Status: %s (0x%x)\n", 1451 ( void * ) inTracePoint.arg1, ( void * ) inTracePoint.arg4, ( unsigned int ) inTracePoint.arg3, errorString, ( unsigned int ) inTracePoint.arg2 ); 1452 1453 } 1454 break; 1455 1456 case kBODoubleCompleteionCode: 1457 { 1458 1459 printf ( "[%10p] BO - DOUBLE Completion\n", ( void * ) inTracePoint.arg1 ); 1460 1461 } 1462 break; 1463 1464 case kBOCompletionDuringTerminationCode: 1465 { 1466 1467 printf ( "[%10p] BO - Completion during termination\n", ( void * ) inTracePoint.arg1 ); 1468 1469 } 1470 break; 1471 1472 case kBOCompletionCode: 1473 { 1474 1475 errorString = StringFromReturnCode ( inTracePoint.arg2 ); 1476 printf ( "[%10p] BO - Completion, State: %s, Status: %s (0x%x), for Request: %p\n", 1477 ( void * ) inTracePoint.arg1, kBulkOnlyStateNames [ (int) inTracePoint.arg3 ], 1478 errorString, ( unsigned int ) inTracePoint.arg2, ( void * ) inTracePoint.arg4 ); 1479 1480 } 1481 break; 1482 1483 default: 1484 { 1485 1486 if ( ( type >= 0x05278800 ) && ( type <= 0x05278BFC ) ) 1487 { 1488 printf ( "[%10p] ??? - UNEXPECTED USB TRACE POINT - %p\n", ( void * ) inTracePoint.arg1, ( void * ) type ); 1489 } 1490 1491 } 1492 break; 1493 1494 } 1495 1496} 1497 1498 1499//----------------------------------------------------------------------------- 1500// Quit 1501//----------------------------------------------------------------------------- 1502 1503static void 1504Quit ( const char * s ) 1505{ 1506 1507 USBSysctlArgs args; 1508 int error; 1509 1510 if ( gTraceEnabled == TRUE ) 1511 EnableTraceBuffer ( 0 ); 1512 1513 if ( gSetRemoveFlag == TRUE ) 1514 RemoveTraceBuffer ( ); 1515 1516 args.type = kUSBTypeDebug; 1517 args.debugFlags = 0; 1518 1519 error = sysctlbyname ( USBMASS_SYSCTL, NULL, NULL, &args, sizeof ( args ) ); 1520 if ( error != 0 ) 1521 { 1522 fprintf ( stderr, "sysctlbyname failed to set old UMC trace flags back\n" ); 1523 } 1524 1525 fprintf ( stderr, "%s: ", gProgramName ); 1526 if ( s != NULL ) 1527 { 1528 fprintf ( stderr, "%s", s ); 1529 } 1530 1531 exit ( 1 ); 1532 1533} 1534 1535 1536//----------------------------------------------------------------------------- 1537// GetDivisor 1538//----------------------------------------------------------------------------- 1539 1540static void 1541GetDivisor ( void ) 1542{ 1543 1544 struct mach_timebase_info mti; 1545 1546 mach_timebase_info ( &mti ); 1547 1548 gDivisor = ( ( double ) mti.denom / ( double ) mti.numer) * 1000; 1549 1550} 1551 1552 1553//----------------------------------------------------------------------------- 1554// LoadUSBMassStorageExtension 1555//----------------------------------------------------------------------------- 1556 1557static void 1558LoadUSBMassStorageExtension ( void ) 1559{ 1560 1561 posix_spawn_file_actions_t fileActions; 1562 char * const argv[] = { ( char * ) "/sbin/kextload", ( char * ) "/System/Library/Extensions/IOUSBMassStorageClass.kext", NULL }; 1563 char * const env[] = { NULL }; 1564 pid_t child = 0; 1565 union wait status; 1566 1567 posix_spawn_file_actions_init ( &fileActions ); 1568 posix_spawn_file_actions_addclose ( &fileActions, STDOUT_FILENO ); 1569 posix_spawn_file_actions_addclose ( &fileActions, STDERR_FILENO ); 1570 1571 posix_spawn ( &child, "/sbin/kextload", &fileActions, NULL, argv, env ); 1572 1573 if ( !( ( wait4 ( child, ( int * ) &status, 0, NULL ) == child ) && ( WIFEXITED ( status ) ) ) ) 1574 { 1575 printf ( "Error loading USB Mass Storage extension\n" ); 1576 } 1577 1578 posix_spawn_file_actions_destroy ( &fileActions ); 1579 1580} 1581 1582 1583//----------------------------------------------------------------------------- 1584// StringFromReturnCode 1585//----------------------------------------------------------------------------- 1586 1587static const char * 1588StringFromReturnCode ( unsigned int returnCode ) 1589{ 1590 1591 const char * string = "UNKNOWN"; 1592 unsigned int i; 1593 1594 static ReturnCodeSpec sReturnCodeSpecs[] = 1595 { 1596 1597 // USB Return codes 1598 { kIOUSBUnknownPipeErr, "kIOUSBUnknownPipeErr" }, 1599 { kIOUSBTooManyPipesErr, "kIOUSBTooManyPipesErr" }, 1600 { kIOUSBNoAsyncPortErr, "kIOUSBNoAsyncPortErr" }, 1601 { kIOUSBNotEnoughPipesErr, "kIOUSBNotEnoughPipesErr" }, 1602 { kIOUSBNotEnoughPowerErr, "kIOUSBNotEnoughPowerErr" }, 1603 { kIOUSBEndpointNotFound, "kIOUSBEndpointNotFound" }, 1604 { kIOUSBConfigNotFound, "kIOUSBConfigNotFound" }, 1605 { kIOUSBTransactionTimeout, "kIOUSBTransactionTimeout" }, 1606 { kIOUSBTransactionReturned, "kIOUSBTransactionReturned" }, 1607 { kIOUSBPipeStalled, "kIOUSBPipeStalled" }, 1608 { kIOUSBInterfaceNotFound, "kIOUSBInterfaceNotFound" }, 1609 { kIOUSBLowLatencyBufferNotPreviouslyAllocated, "kIOUSBLowLatencyBufferNotPreviouslyAllocated" }, 1610 { kIOUSBLowLatencyFrameListNotPreviouslyAllocated, "kIOUSBLowLatencyFrameListNotPreviouslyAllocated" }, 1611 { kIOUSBHighSpeedSplitError, "kIOUSBHighSpeedSplitError" }, 1612 { kIOUSBSyncRequestOnWLThread, "kIOUSBSyncRequestOnWLThread" }, 1613 { kIOUSBDeviceNotHighSpeed, "kIOUSBDeviceNotHighSpeed" }, 1614 { kIOUSBLinkErr, "kIOUSBLinkErr" }, 1615 { kIOUSBNotSent2Err, "kIOUSBNotSent2Err" }, 1616 { kIOUSBNotSent1Err, "kIOUSBNotSent1Err" }, 1617 { kIOUSBBufferUnderrunErr, "kIOUSBBufferUnderrunErr" }, 1618 { kIOUSBBufferOverrunErr, "kIOUSBBufferOverrunErr" }, 1619 { kIOUSBReserved2Err, "kIOUSBReserved2Err" }, 1620 { kIOUSBReserved1Err, "kIOUSBReserved1Err" }, 1621 { kIOUSBWrongPIDErr, "kIOUSBWrongPIDErr" }, 1622 { kIOUSBPIDCheckErr, "kIOUSBPIDCheckErr" }, 1623 { kIOUSBDataToggleErr, "kIOUSBDataToggleErr" }, 1624 { kIOUSBBitstufErr, "kIOUSBBitstufErr" }, 1625 { kIOUSBCRCErr, "kIOUSBCRCErr" }, 1626 1627 // IOReturn codes 1628 { kIOReturnSuccess, "kIOReturnSuccess" }, 1629 { kIOReturnError, "kIOReturnError" }, 1630 { kIOReturnNoMemory, "kIOReturnNoMemory" }, 1631 { kIOReturnNoResources, "kIOReturnNoResources" }, 1632 { kIOReturnIPCError, "kIOReturnIPCError" }, 1633 { kIOReturnNoDevice, "kIOReturnNoDevice" }, 1634 { kIOReturnNotPrivileged, "kIOReturnNotPrivileged" }, 1635 { kIOReturnBadArgument, "kIOReturnBadArgument" }, 1636 { kIOReturnLockedRead, "kIOReturnLockedRead" }, 1637 { kIOReturnLockedWrite, "kIOReturnLockedWrite" }, 1638 { kIOReturnExclusiveAccess, "kIOReturnExclusiveAccess" }, 1639 { kIOReturnBadMessageID, "kIOReturnBadMessageID" }, 1640 { kIOReturnUnsupported, "kIOReturnUnsupported" }, 1641 { kIOReturnVMError, "kIOReturnVMError" }, 1642 { kIOReturnInternalError, "kIOReturnInternalError" }, 1643 { kIOReturnIOError, "kIOReturnIOError" }, 1644 { kIOReturnCannotLock, "kIOReturnCannotLock" }, 1645 { kIOReturnNotOpen, "kIOReturnNotOpen" }, 1646 { kIOReturnNotReadable, "kIOReturnNotReadable" }, 1647 { kIOReturnNotWritable, "kIOReturnNotWritable" }, 1648 { kIOReturnNotAligned, "kIOReturnNotAligned" }, 1649 { kIOReturnBadMedia, "kIOReturnBadMedia" }, 1650 { kIOReturnStillOpen, "kIOReturnStillOpen" }, 1651 { kIOReturnRLDError, "kIOReturnRLDError" }, 1652 { kIOReturnDMAError, "kIOReturnDMAError" }, 1653 { kIOReturnBusy, "kIOReturnBusy" }, 1654 { kIOReturnTimeout, "kIOReturnTimeout" }, 1655 { kIOReturnOffline, "kIOReturnOffline" }, 1656 { kIOReturnNotReady, "kIOReturnNotReady" }, 1657 { kIOReturnNotAttached, "kIOReturnNotAttached" }, 1658 { kIOReturnNoChannels, "kIOReturnNoChannels" }, 1659 { kIOReturnNoSpace, "kIOReturnNoSpace" }, 1660 { kIOReturnPortExists, "kIOReturnPortExists" }, 1661 { kIOReturnCannotWire, "kIOReturnCannotWire" }, 1662 { kIOReturnNoInterrupt, "kIOReturnNoInterrupt" }, 1663 { kIOReturnNoFrames, "kIOReturnNoFrames" }, 1664 { kIOReturnMessageTooLarge, "kIOReturnMessageTooLarge" }, 1665 { kIOReturnNotPermitted, "kIOReturnNotPermitted" }, 1666 { kIOReturnNoPower, "kIOReturnNoPower" }, 1667 { kIOReturnNoMedia, "kIOReturnNoMedia" }, 1668 { kIOReturnUnformattedMedia, "kIOReturnUnformattedMedia" }, 1669 { kIOReturnUnsupportedMode, "kIOReturnUnsupportedMode" }, 1670 { kIOReturnUnderrun, "kIOReturnUnderrun" }, 1671 { kIOReturnOverrun, "kIOReturnOverrun" }, 1672 { kIOReturnDeviceError, "kIOReturnDeviceError" }, 1673 { kIOReturnNoCompletion, "kIOReturnNoCompletion" }, 1674 { kIOReturnAborted, "kIOReturnAborted" }, 1675 { kIOReturnNoBandwidth, "kIOReturnNoBandwidth" }, 1676 { kIOReturnNotResponding, "kIOReturnNotResponding" }, 1677 { kIOReturnIsoTooOld, "kIOReturnIsoTooOld" }, 1678 { kIOReturnIsoTooNew, "kIOReturnIsoTooNew" }, 1679 { kIOReturnNotFound, "kIOReturnNotFound" }, 1680 { kIOReturnInvalid, "kIOReturnInvalid" } 1681 }; 1682 1683 for ( i = 0; i < ( sizeof ( sReturnCodeSpecs ) / sizeof ( sReturnCodeSpecs[0] ) ); i++ ) 1684 { 1685 1686 if ( returnCode == sReturnCodeSpecs[i].returnCode ) 1687 { 1688 1689 string = sReturnCodeSpecs[i].string; 1690 break; 1691 1692 } 1693 1694 } 1695 1696 return string; 1697 1698} 1699 1700 1701//----------------------------------------------------------------------------- 1702// ProcessSubclassTracePoint 1703//----------------------------------------------------------------------------- 1704 1705void 1706ProcessSubclassTracePoint ( kd_buf inTracePoint ) 1707{ 1708 1709 UInt32 subclassID = 0; 1710 UInt32 subclassCode = 0; 1711 1712 subclassID = ( inTracePoint.arg1 >> 24 ) & 0xFF; 1713 subclassCode = inTracePoint.arg1 & 0xFFFFFF; 1714 1715 switch ( subclassID ) 1716 { 1717 1718 case kSubclassCode_AppleUSBODD: 1719 { 1720 ProcessAppleUSBODDSubclassTracePoint ( inTracePoint, subclassCode ); 1721 } 1722 break; 1723 1724 case kSubclassCode_AppleUSBCardReaderUMC: 1725 { 1726 ProcessAppleUSBCardReaderUMCSubclassTracePoint ( inTracePoint, subclassCode ); 1727 } 1728 break; 1729 1730 default: 1731 { 1732 printf ( "Recieved request for subclassID=0x%lx, but know of no such ssubclassID\n", ( unsigned long ) subclassID ); 1733 } 1734 1735 } 1736 1737 return; 1738 1739} 1740 1741 1742//----------------------------------------------------------------------------- 1743// ProcessAppleUSBODDSubclassTracePoint 1744//----------------------------------------------------------------------------- 1745 1746void 1747ProcessAppleUSBODDSubclassTracePoint ( kd_buf inTracePoint, UInt32 inSubclassCode ) 1748{ 1749 1750 switch ( inSubclassCode ) 1751 { 1752 1753 case kAppleUSBODD_probe: 1754 { 1755 1756 printf ( "[%10p] AUO - Probe returning instance %p\n", 1757 ( void * ) inTracePoint.arg2, ( void * ) inTracePoint.arg3 ); 1758 1759 } 1760 break; 1761 1762 case kAppleUSBODD_start: 1763 { 1764 1765 printf ( "[%10p] AUO - Start returning %d\n", 1766 ( void * ) inTracePoint.arg2, ( int ) inTracePoint.arg3 ); 1767 1768 } 1769 break; 1770 1771 case kAppleUSBODD_requestedExtraPower: 1772 { 1773 1774 printf ( "[%10p] AUO - BeginProvidedServices requested %ldma of extra power and was granted %ldma\n", 1775 ( void * ) inTracePoint.arg2, ( unsigned long ) inTracePoint.arg3, ( unsigned long ) inTracePoint.arg4 ); 1776 1777 } 1778 break; 1779 1780 case kAppleUSBODD_isMacModelSupported: 1781 { 1782 1783 printf ( "[%10p] AUO - isMacModelSupported returning %d\n", 1784 ( void * ) inTracePoint.arg2, ( int ) inTracePoint.arg3 ); 1785 1786 } 1787 break; 1788 1789 case kAppleUSBODD_FindACPIPlatformDevice: 1790 { 1791 1792 printf ( "[%10p] AUO - FindACPIPlatformDevice found device %p\n", 1793 ( void * ) inTracePoint.arg2, ( void * ) inTracePoint.arg3 ); 1794 1795 } 1796 break; 1797 1798 case kAppleUSBODD_CheckForACPIFlags: 1799 { 1800 1801 printf ( "[%10p] AUO - CheckForACPIFlasgs found device 0x%lx\n", 1802 ( void * ) inTracePoint.arg2, ( unsigned long ) inTracePoint.arg3 ); 1803 1804 } 1805 break; 1806 1807 default: 1808 { 1809 printf ( "Recieved request for intSubclassCode=0x%lx for AppleUSBODD, but know of no such intSubclassCode\n", ( unsigned long )inSubclassCode ); 1810 } 1811 1812 } 1813 1814} 1815 1816 1817//----------------------------------------------------------------------------- 1818// ProcessAppleUSBCardReaderUMCSubclassTracePoint 1819//----------------------------------------------------------------------------- 1820 1821void 1822ProcessAppleUSBCardReaderUMCSubclassTracePoint ( kd_buf inTracePoint, UInt32 inSubclassCode ) 1823{ 1824 1825 switch ( inSubclassCode ) 1826 { 1827 1828 case kAppleUSBCardReaderUMC_HandlePowerChange: 1829 { 1830 1831 printf ( "[%10p] AUCRU - HandlePowerChange current power state %d, requested power state %d\n", 1832 ( void * ) inTracePoint.arg2, ( int ) inTracePoint.arg3, ( int ) inTracePoint.arg4 ); 1833 1834 } 1835 break; 1836 1837 case kAppleUSBCardReaderUMC_start: 1838 { 1839 1840 printf ( "[%10p] AUCRU - start returning %d\n", 1841 ( void * ) inTracePoint.arg2, ( int ) inTracePoint.arg3 ); 1842 1843 } 1844 break; 1845 1846 case kAppleUSBCardReaderUMC_stop: 1847 { 1848 printf ( "[%10p] AUCRU - stop fProposedPowerState=%lu fCurrentPowerState=%lu\n", 1849 ( void * ) inTracePoint.arg2, ( unsigned long ) inTracePoint.arg3, ( unsigned long ) inTracePoint.arg4 ); 1850 } 1851 break; 1852 1853 case kAppleUSBCardReaderUMC_stop_2: 1854 { 1855 printf ( "[%10p] AUCRU - stop sleeptype=%lu fDeviceRequiresReset=%d\n", 1856 ( void * ) inTracePoint.arg2, ( unsigned long ) inTracePoint.arg3, ( int ) inTracePoint.arg4 ); 1857 } 1858 break; 1859 1860 case kAppleUSBCardReaderUMC_message: 1861 { 1862 printf ( "[%10p] AUCRU - message type=0x%x argument=0x%x\n", ( void * ) inTracePoint.arg2, 1863 ( int ) inTracePoint.arg3, ( int ) inTracePoint.arg4 ); 1864 } 1865 break; 1866 1867 case kAppleUSBCardReaderUMC_setProperty: 1868 { 1869 printf ( "[%10p] AUCRU - setProperty\n", ( void * ) inTracePoint.arg2 ); 1870 } 1871 break; 1872 1873 case kAppleUSBCardReaderUMC_gpioMediaDetectFired: 1874 { 1875 printf ( "[%10p] AUCRU - GPIO media detect\n", ( void * ) inTracePoint.arg2 ); 1876 } 1877 break; 1878 1879 case kAppleUSBCardReaderUMC_gpioMediaDetectEnable: 1880 { 1881 1882 if ( inTracePoint.arg3 == 2 ) 1883 { 1884 printf ( "[%10p] AUCRU - GPIO media detect SETUP and ENABLED IOIES=%p\n", ( void * ) inTracePoint.arg2, ( void * ) inTracePoint.arg4 ); 1885 } 1886 1887 else if ( inTracePoint.arg3 == 1 ) 1888 { 1889 printf ( "[%10p] AUCRU - GPIO media detect ENABLED IOIES=%p\n", ( void * ) inTracePoint.arg2, ( void * ) inTracePoint.arg4 ); 1890 } 1891 1892 else 1893 { 1894 printf ( "[%10p] AUCRU - GPIO media detect DISABLED IOIES=%p\n", ( void * ) inTracePoint.arg2, ( void * ) inTracePoint.arg4 ); 1895 } 1896 1897 } 1898 break; 1899 1900 case kAppleUSBCardReaderUMC_controllerReset: 1901 { 1902 printf ( "[%10p] AUCRU - SDControllerReset returned=0x%x\n", ( void * ) inTracePoint.arg2, ( int ) inTracePoint.arg3 ); 1903 } 1904 break; 1905 1906 case kAppleUSBCardReaderUMC_powerControl: 1907 { 1908 1909 if ( inTracePoint.arg4 != 0 ) 1910 { 1911 printf ( "[%10p] AUCRU - SDControllerPower powering ON returned=0x%x\n", ( void * ) inTracePoint.arg2, ( int ) inTracePoint.arg3 ); 1912 } 1913 1914 else 1915 { 1916 printf ( "[%10p] AUCRU - SDControllerPower powering OFF returned=0x%x\n", ( void * ) inTracePoint.arg2, ( int ) inTracePoint.arg3 ); 1917 } 1918 1919 } 1920 break; 1921 1922 case kAppleUSBCardReaderUMC_waitForReconnect: 1923 { 1924 1925 if ( inTracePoint.arg4 != 0 ) 1926 { 1927 printf ( "[%10p] AUCRU - GatedWaitForReconnect exiting returned=0x%x\n", ( void * ) inTracePoint.arg2, ( int ) inTracePoint.arg3 ); 1928 } 1929 1930 else 1931 { 1932 printf ( "[%10p] AUCRU - GatedWaitForReconnect entered returned=0x%x\n", ( void * ) inTracePoint.arg2, ( int ) inTracePoint.arg3 ); 1933 } 1934 1935 } 1936 break; 1937 1938 case kAppleUSBCardReaderUMC_systemWillShutdown: 1939 { 1940 printf ( "[%10p] AUCRU - systemWillShutdown specifier=0x%x\n", ( void * ) inTracePoint.arg2, ( int ) inTracePoint.arg3 ); 1941 } 1942 break; 1943 1944 case kAppleUSBCardReaderUMC_generalPurpose: 1945 { 1946 printf ( "[%10p] AUCRU - General Purpose 0x%x 0x%x\n", ( void * ) inTracePoint.arg2, 1947 ( int ) inTracePoint.arg3, ( int ) inTracePoint.arg4 ); 1948 } 1949 break; 1950 1951 default: 1952 { 1953 printf ( "Recieved request for intSubclassCode=0x%lx for AppleUSBCardReaderUMC, but know of no such intSubclassCode\n", ( unsigned long ) inSubclassCode ); 1954 } 1955 1956 } 1957 1958} 1959 1960 1961//----------------------------------------------------------------------------- 1962// EOF 1963//----------------------------------------------------------------------------- 1964