1/* 2 * Copyright (c) 2008 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 26//----------------------------------------------------------------------------- 27// Includes 28//----------------------------------------------------------------------------- 29 30#include <errno.h> 31#include <getopt.h> 32#include <signal.h> 33#include <spawn.h> 34#include <stdlib.h> 35#include <stdio.h> 36#include <stdint.h> 37#include <string.h> 38#include <unistd.h> 39#include <libutil.h> 40 41#include <mach/clock_types.h> 42#include <mach/mach_time.h> 43 44#include <sys/types.h> 45#include <sys/param.h> 46#include <sys/sysctl.h> 47#include <sys/time.h> 48#include <sys/wait.h> 49 50#ifndef KERNEL_PRIVATE 51#define KERNEL_PRIVATE 52#include <sys/kdebug.h> 53#undef KERNEL_PRIVATE 54#else 55#include <sys/kdebug.h> 56#endif /*KERNEL_PRIVATE*/ 57 58#include <IOKit/scsi/IOSCSIArchitectureModelFamilyTimestamps.h> 59#include <IOKit/scsi/IOSCSIArchitectureModelFamilyDebugging.h> 60#include <IOKit/storage/ata/IOATAPIProtocolTransportTimeStamps.h> 61#include <IOKit/storage/ata/IOATAPIProtocolTransportDebugging.h> 62 63#define DEBUG 0 64 65 66//----------------------------------------------------------------------------- 67// Structures 68//----------------------------------------------------------------------------- 69 70typedef struct SCSITaskLogEntry 71{ 72 TAILQ_ENTRY(SCSITaskLogEntry) chain; 73 unsigned int taskID; 74 uint8_t cdb[16]; 75} SCSITaskLogEntry; 76 77 78//----------------------------------------------------------------------------- 79// Constants 80//----------------------------------------------------------------------------- 81 82enum 83{ 84 kSCSITaskTracePointCDBLog1Code = SCSITASK_TRACE ( kSCSITaskTracePointCDBLog1 ), 85 kSCSITaskTracePointCDBLog2Code = SCSITASK_TRACE ( kSCSITaskTracePointCDBLog2 ), 86 kSCSITaskTracePointResponseLog1Code = SCSITASK_TRACE ( kSCSITaskTracePointResponseLog1 ), 87 kSCSITaskTracePointResponseLog2Code = SCSITASK_TRACE ( kSCSITaskTracePointResponseLog2 ), 88}; 89 90 91enum 92{ 93 kATADeviceInfoCode = ATAPI_TRACE( kATADeviceInfo ), 94 kATASendSCSICommandCode = ATAPI_TRACE( kATASendSCSICommand ), 95 kATASendSCSICommandFailedCode = ATAPI_TRACE( kATASendSCSICommandFailed ), 96 kATACompleteSCSICommandCode = ATAPI_TRACE( kATACompleteSCSICommand ), 97 kATAAbortCode = ATAPI_TRACE( kATAAbort ), 98 kATAResetCode = ATAPI_TRACE( kATAReset ), 99 kATAResetCompleteCode = ATAPI_TRACE( kATAResetComplete ), 100 kATAHandlePowerOnCode = ATAPI_TRACE( kATAHandlePowerOn ), 101 kATAPowerOnResetCode = ATAPI_TRACE( kATAPowerOnReset ), 102 kATAPowerOnNoResetCode = ATAPI_TRACE( kATAPowerOnNoReset ), 103 kATAHandlePowerOffCode = ATAPI_TRACE( kATAHandlePowerOff ), 104 kATADriverPowerOffCode = ATAPI_TRACE( kATADriverPowerOff ), 105}; 106 107 108#define kTraceBufferSampleSize 60000 109#define kMicrosecondsPerSecond 1000000 110#define kMicrosecondsPerMillisecond 1000 111 112 113//----------------------------------------------------------------------------- 114// Globals 115//----------------------------------------------------------------------------- 116 117int gBiasSeconds = 0; 118double gDivisor = 0.0; /* Trace divisor converts to microseconds */ 119kd_buf * gTraceBuffer = NULL; 120boolean_t gTraceEnabled = FALSE; 121boolean_t gSetRemoveFlag = TRUE; 122boolean_t gVerbose = FALSE; 123boolean_t gEnableTraceOnly = FALSE; 124const char * gProgramName = NULL; 125uint32_t gPrintfMask = 0; 126uint32_t gSavedSAMTraceMask = 0; 127uint32_t gSavedATAPIDebugMask = 0; 128 129TAILQ_HEAD(SCSITaskLogEntryHead, SCSITaskLogEntry) gListHead = TAILQ_HEAD_INITIALIZER(gListHead); 130 131//----------------------------------------------------------------------------- 132// Prototypes 133//----------------------------------------------------------------------------- 134 135static void 136EnableTraceBuffer ( int val ); 137 138static void 139CollectTrace ( void ); 140 141static void 142SignalHandler ( int signal ); 143 144static void 145GetDivisor ( void ); 146 147static void 148RegisterSignalHandlers ( void ); 149 150static void 151AllocateTraceBuffer ( void ); 152 153static void 154RemoveTraceBuffer ( void ); 155 156static void 157SetTraceBufferSize ( int nbufs ); 158 159static void 160Quit ( const char * s ); 161 162static void 163InitializeTraceBuffer ( void ); 164 165static void 166ParseArguments ( int argc, const char * argv[] ); 167 168static void 169PrintUsage ( void ); 170 171static void 172LoadATAPIExtension ( void ); 173 174static void 175ResetDebugFlags ( void ); 176 177 178//----------------------------------------------------------------------------- 179// Main 180//----------------------------------------------------------------------------- 181 182int 183main ( int argc, const char * argv[] ) 184{ 185 186 SAMSysctlArgs samArgs; 187 ATAPISysctlArgs atapiArgs; 188 int error; 189 190 gProgramName = argv[0]; 191 192 if ( geteuid ( ) != 0 ) 193 { 194 195 fprintf ( stderr, "'%s' must be run as root...\n", gProgramName ); 196 exit ( 1 ); 197 198 } 199 200 if ( reexec_to_match_kernel ( ) ) 201 { 202 203 fprintf ( stderr, "Could not re-execute to match kernel architecture. (Error = %d)\n", errno ); 204 exit ( 1 ); 205 206 } 207 208 // Get program arguments. 209 ParseArguments ( argc, argv ); 210 211 bzero ( &samArgs, sizeof ( samArgs ) ); 212 bzero ( &atapiArgs, sizeof ( atapiArgs ) ); 213 214 samArgs.type = kSAMTypeDebug; 215 samArgs.operation = kSAMOperationGetFlags; 216 samArgs.validBits = kSAMTraceFlagsValidMask; 217 218 error = sysctlbyname ( SAM_SYSCTL, NULL, NULL, &samArgs, sizeof ( samArgs ) ); 219 if ( error != 0 ) 220 { 221 fprintf ( stderr, "sysctlbyname failed to get old samtrace flags\n" ); 222 } 223 224 gSavedSAMTraceMask = samArgs.samTraceFlags; 225 226 atapiArgs.type = kATAPITypeDebug; 227 atapiArgs.operation = kATAPIOperationGetFlags; 228 229 error = sysctlbyname ( ATAPI_SYSCTL, NULL, NULL, &atapiArgs, sizeof ( atapiArgs ) ); 230 if ( error != 0 ) 231 { 232 233 LoadATAPIExtension ( ); 234 235 error = sysctlbyname ( ATAPI_SYSCTL, NULL, NULL, &atapiArgs, sizeof ( atapiArgs ) ); 236 if ( error != 0 ) 237 { 238 fprintf ( stderr, "sysctlbyname failed to get old atapi debug flags second time\n" ); 239 } 240 241 } 242 243 gSavedATAPIDebugMask = atapiArgs.debugFlags; 244 245 samArgs.type = kSAMTypeDebug; 246 samArgs.operation = kSAMOperationSetFlags; 247 samArgs.validBits = kSAMTraceFlagsValidMask; 248 samArgs.samDebugFlags = 0; 249 samArgs.samTraceFlags = gPrintfMask; 250 251 error = sysctlbyname ( SAM_SYSCTL, NULL, NULL, &samArgs, sizeof ( samArgs ) ); 252 if ( error != 0 ) 253 { 254 fprintf ( stderr, "sysctlbyname failed to set new samtrace flags\n" ); 255 } 256 257 atapiArgs.type = kATAPITypeDebug; 258 atapiArgs.operation = kATAPIOperationSetFlags; 259 atapiArgs.debugFlags = 1; 260 261 error = sysctlbyname ( ATAPI_SYSCTL, NULL, NULL, &atapiArgs, sizeof ( atapiArgs ) ); 262 if ( error != 0 ) 263 { 264 fprintf ( stderr, "sysctlbyname failed to set new atapi debug flags\n" ); 265 } 266 267#if DEBUG 268 printf ( "gSavedSAMTraceMask = 0x%08X\n", gSavedSAMTraceMask ); 269 printf ( "gSavedATAPIDebugMask = 0x%08X\n", gSavedATAPIDebugMask ); 270 printf ( "gPrintfMask = 0x%08X\n", gPrintfMask ); 271 printf ( "gVerbose = %s\n", gVerbose == TRUE ? "True" : "False" ); 272 fflush ( stdout ); 273#endif 274 275 // Set up signal handlers. 276 RegisterSignalHandlers ( ); 277 278 // Allocate trace buffer. 279 AllocateTraceBuffer ( ); 280 281 // Remove the trace buffer. 282 RemoveTraceBuffer ( ); 283 284 // Set the new trace buffer size. 285 SetTraceBufferSize ( kTraceBufferSampleSize ); 286 287 // Initialize the trace buffer. 288 InitializeTraceBuffer ( ); 289 290 // Enable the trace buffer. 291 EnableTraceBuffer ( 1 ); 292 293 // Get the clock divisor. 294 GetDivisor ( ); 295 296 // Does the user only want the trace points enabled and no logging? 297 if ( gEnableTraceOnly == FALSE ) 298 { 299 300 printf ( "ATAPILogger v1.0\n" ); 301 302 // No, they want logging. Start main loop. 303 while ( 1 ) 304 { 305 306 usleep ( 20 * kMicrosecondsPerMillisecond ); 307 CollectTrace ( ); 308 309 } 310 311 } 312 313 return 0; 314 315} 316 317 318//----------------------------------------------------------------------------- 319// PrintUsage 320//----------------------------------------------------------------------------- 321 322static void 323PrintUsage ( void ) 324{ 325 326 printf ( "\n" ); 327 printf ( "Usage: %s [--help] [--enable] [--disable] [--scsitask] [--all] [--verbose]\n", gProgramName ); 328 printf ( "\n" ); 329 330 exit ( 0 ); 331 332} 333 334 335//----------------------------------------------------------------------------- 336// ParseArguments 337//----------------------------------------------------------------------------- 338 339static void 340ParseArguments ( int argc, const char * argv[] ) 341{ 342 343 int c; 344 struct option long_options[] = 345 { 346 { "all", no_argument, 0, 'a' }, 347 { "enable", no_argument, 0, 'e' }, 348 { "disable", no_argument, 0, 'd' }, 349 { "scsitask", no_argument, 0, 's' }, 350 { "verbose", no_argument, 0, 'v' }, 351 { "help", no_argument, 0, 'h' }, 352 { 0, 0, 0, 0 } 353 }; 354 355 // If no args specified, enable firewire sbp2 driver logging only... 356 if ( argc == 1 ) 357 { 358 return; 359 } 360 361 while ( ( c = getopt_long ( argc, ( char * const * ) argv , "asptlgbrmvh?", long_options, NULL ) ) != -1 ) 362 { 363 364 switch ( c ) 365 { 366 367 case 'a': 368 gPrintfMask = ~0; 369 break; 370 371 case 'e': 372 gEnableTraceOnly = TRUE; 373 break; 374 375 case 'd': 376 gSavedSAMTraceMask = 0; 377 gSavedATAPIDebugMask = 0; 378 gSetRemoveFlag = FALSE; 379 Quit ( "Quit via user-specified trace disable\n" ); 380 break; 381 382 case 's': 383 gPrintfMask |= (1 << kSAMClassSCSITask); 384 break; 385 386 case 'v': 387 gVerbose = TRUE; 388 break; 389 390 case 'h': 391 PrintUsage ( ); 392 break; 393 394 default: 395 break; 396 397 } 398 399 } 400 401} 402 403 404//----------------------------------------------------------------------------- 405// RegisterSignalHandlers 406//----------------------------------------------------------------------------- 407 408static void 409RegisterSignalHandlers ( void ) 410{ 411 412 signal ( SIGINT, SignalHandler ); 413 signal ( SIGQUIT, SignalHandler ); 414 signal ( SIGHUP, SignalHandler ); 415 signal ( SIGTERM, SignalHandler ); 416 417} 418 419 420//----------------------------------------------------------------------------- 421// AllocateTraceBuffer 422//----------------------------------------------------------------------------- 423 424static void 425AllocateTraceBuffer ( void ) 426{ 427 428 gTraceBuffer = ( kd_buf * ) malloc ( kTraceBufferSampleSize * sizeof ( kd_buf ) ); 429 if ( gTraceBuffer == NULL ) 430 { 431 Quit ( "Can't allocate memory for tracing info\n" ); 432 } 433 434} 435 436 437//----------------------------------------------------------------------------- 438// SignalHandler 439//----------------------------------------------------------------------------- 440 441static void 442SignalHandler ( int signal ) 443{ 444 445#pragma unused ( signal ) 446 447 EnableTraceBuffer ( 0 ); 448 RemoveTraceBuffer ( ); 449 ResetDebugFlags ( ); 450 451 exit ( 0 ); 452 453} 454 455 456//----------------------------------------------------------------------------- 457// EnableTraceBuffer 458//----------------------------------------------------------------------------- 459 460static void 461EnableTraceBuffer ( int val ) 462{ 463 464 int mib[6]; 465 size_t needed; 466 467 mib[0] = CTL_KERN; 468 mib[1] = KERN_KDEBUG; 469 mib[2] = KERN_KDENABLE; /* protocol */ 470 mib[3] = val; 471 mib[4] = 0; 472 mib[5] = 0; /* no flags */ 473 474 if ( sysctl ( mib, 4, NULL, &needed, NULL, 0 ) < 0 ) 475 Quit ( "trace facility failure, KERN_KDENABLE\n" ); 476 477 if ( val ) 478 gTraceEnabled = TRUE; 479 else 480 gTraceEnabled = FALSE; 481 482} 483 484 485//----------------------------------------------------------------------------- 486// SetTraceBufferSize 487//----------------------------------------------------------------------------- 488 489static void 490SetTraceBufferSize ( int nbufs ) 491{ 492 493 int mib[6]; 494 size_t needed; 495 496 mib[0] = CTL_KERN; 497 mib[1] = KERN_KDEBUG; 498 mib[2] = KERN_KDSETBUF; 499 mib[3] = nbufs; 500 mib[4] = 0; 501 mib[5] = 0; /* no flags */ 502 503 if ( sysctl ( mib, 4, NULL, &needed, NULL, 0 ) < 0 ) 504 Quit ( "trace facility failure, KERN_KDSETBUF\n" ); 505 506 mib[0] = CTL_KERN; 507 mib[1] = KERN_KDEBUG; 508 mib[2] = KERN_KDSETUP; 509 mib[3] = 0; 510 mib[4] = 0; 511 mib[5] = 0; /* no flags */ 512 513 if ( sysctl ( mib, 3, NULL, &needed, NULL, 0 ) < 0 ) 514 Quit ( "trace facility failure, KERN_KDSETUP\n" ); 515 516} 517 518 519//----------------------------------------------------------------------------- 520// GetTraceBufferInfo 521//----------------------------------------------------------------------------- 522 523static void 524GetTraceBufferInfo ( kbufinfo_t * val ) 525{ 526 527 int mib[6]; 528 size_t needed; 529 530 needed = sizeof ( *val ); 531 532 mib[0] = CTL_KERN; 533 mib[1] = KERN_KDEBUG; 534 mib[2] = KERN_KDGETBUF; 535 mib[3] = 0; 536 mib[4] = 0; 537 mib[5] = 0; /* no flags */ 538 539 if ( sysctl ( mib, 3, val, &needed, 0, 0 ) < 0 ) 540 Quit ( "trace facility failure, KERN_KDGETBUF\n" ); 541 542} 543 544 545//----------------------------------------------------------------------------- 546// RemoveTraceBuffer 547//----------------------------------------------------------------------------- 548 549static void 550RemoveTraceBuffer ( void ) 551{ 552 553 int mib[6]; 554 size_t needed; 555 556 errno = 0; 557 558 mib[0] = CTL_KERN; 559 mib[1] = KERN_KDEBUG; 560 mib[2] = KERN_KDREMOVE; /* protocol */ 561 mib[3] = 0; 562 mib[4] = 0; 563 mib[5] = 0; /* no flags */ 564 565 if ( sysctl ( mib, 3, NULL, &needed, NULL, 0 ) < 0 ) 566 { 567 568 gSetRemoveFlag = FALSE; 569 570 if ( errno == EBUSY ) 571 Quit ( "The trace facility is currently in use...\n fs_usage, sc_usage, and latency use this feature.\n\n" ); 572 573 else 574 Quit ( "Trace facility failure, KERN_KDREMOVE\n" ); 575 576 } 577 578} 579 580 581//----------------------------------------------------------------------------- 582// InitializeTraceBuffer 583//----------------------------------------------------------------------------- 584 585static void 586InitializeTraceBuffer ( void ) 587{ 588 589 int mib[6]; 590 size_t needed; 591 kd_regtype kr; 592 593 kr.type = KDBG_RANGETYPE; 594 kr.value1 = 0; 595 kr.value2 = -1; 596 597 needed = sizeof ( kd_regtype ); 598 599 mib[0] = CTL_KERN; 600 mib[1] = KERN_KDEBUG; 601 mib[2] = KERN_KDSETREG; 602 mib[3] = 0; 603 mib[4] = 0; 604 mib[5] = 0; /* no flags */ 605 606 if ( sysctl ( mib, 3, &kr, &needed, NULL, 0 ) < 0 ) 607 Quit ( "trace facility failure, KERN_KDSETREG\n" ); 608 609 mib[0] = CTL_KERN; 610 mib[1] = KERN_KDEBUG; 611 mib[2] = KERN_KDSETUP; 612 mib[3] = 0; 613 mib[4] = 0; 614 mib[5] = 0; /* no flags */ 615 616 if ( sysctl ( mib, 3, NULL, &needed, NULL, 0 ) < 0 ) 617 Quit ( "trace facility failure, KERN_KDSETUP\n" ); 618 619} 620 621 622//----------------------------------------------------------------------------- 623// CollectTrace 624//----------------------------------------------------------------------------- 625 626static void 627CollectTrace ( void ) 628{ 629 630 int mib[6]; 631 int index; 632 int count; 633 size_t needed; 634 kbufinfo_t bufinfo = { 0, 0, 0, 0, 0 }; 635 636 /* Get kernel buffer information */ 637 GetTraceBufferInfo ( &bufinfo ); 638 639 needed = bufinfo.nkdbufs * sizeof ( kd_buf ); 640 mib[0] = CTL_KERN; 641 mib[1] = KERN_KDEBUG; 642 mib[2] = KERN_KDREADTR; 643 mib[3] = 0; 644 mib[4] = 0; 645 mib[5] = 0; /* no flags */ 646 647 if ( sysctl ( mib, 3, gTraceBuffer, &needed, NULL, 0 ) < 0 ) 648 Quit ( "trace facility failure, KERN_KDREADTR\n" ); 649 650 count = needed; 651 652 if ( bufinfo.flags & KDBG_WRAPPED ) 653 { 654 655 EnableTraceBuffer ( 0 ); 656 EnableTraceBuffer ( 1 ); 657 658 } 659 660 for ( index = 0; index < count; index++ ) 661 { 662 663 int debugID; 664 int type; 665 uint64_t now; 666 int64_t usecs; 667 int secs; 668 time_t currentTime; 669 670 debugID = gTraceBuffer[index].debugid; 671 type = debugID & ~(DBG_FUNC_START | DBG_FUNC_END); 672 673 now = gTraceBuffer[index].timestamp & KDBG_TIMESTAMP_MASK; 674 675 if ( index == 0 ) 676 { 677 678 /* 679 * Compute bias seconds after each trace buffer read. 680 * This helps resync timestamps with the system clock 681 * in the event of a system sleep. 682 */ 683 usecs = ( int64_t )( now / gDivisor ); 684 secs = usecs / kMicrosecondsPerSecond; 685 currentTime = time ( NULL ); 686 gBiasSeconds = currentTime - secs; 687 688 } 689 690 switch ( type ) 691 { 692 693 case kSCSITaskTracePointCDBLog1Code: 694 { 695 696 SCSITaskLogEntry * entry = NULL; 697 698 // If this isn't asked for, don't do any work. 699 if ( ( gPrintfMask & ( 1 << kSAMClassSCSITask ) ) == 0 ) 700 continue; 701 702 entry = TAILQ_FIRST ( &gListHead ); 703 while ( entry != NULL ) 704 { 705 706 if ( entry->taskID == gTraceBuffer[index].arg2 ) 707 { 708 709 break; 710 711 } 712 713 entry = TAILQ_NEXT ( entry, chain ); 714 715 } 716 717 if ( entry == NULL ) 718 { 719 720 entry = ( SCSITaskLogEntry * ) malloc ( sizeof ( SCSITaskLogEntry ) ); 721 TAILQ_INSERT_TAIL ( &gListHead, entry, chain ); 722 723 } 724 725 bzero ( entry->cdb, sizeof ( entry->cdb ) ); 726 727 entry->taskID = gTraceBuffer[index].arg2; 728 entry->cdb[0] = gTraceBuffer[index].arg3 & 0xFF; 729 entry->cdb[1] = ( gTraceBuffer[index].arg3 >> 8 ) & 0xFF; 730 entry->cdb[2] = ( gTraceBuffer[index].arg3 >> 16 ) & 0xFF; 731 entry->cdb[3] = ( gTraceBuffer[index].arg3 >> 24 ) & 0xFF; 732 entry->cdb[4] = gTraceBuffer[index].arg4 & 0xFF; 733 entry->cdb[5] = ( gTraceBuffer[index].arg4 >> 8 ) & 0xFF; 734 entry->cdb[6] = ( gTraceBuffer[index].arg4 >> 16 ) & 0xFF; 735 entry->cdb[7] = ( gTraceBuffer[index].arg4 >> 24 ) & 0xFF; 736 737 } 738 break; 739 740 case kSCSITaskTracePointCDBLog2Code: 741 { 742 743 // If this isn't asked for, don't do any work. 744 if ( ( gPrintfMask & ( 1 << kSAMClassSCSITask ) ) == 0 ) 745 continue; 746 747 if ( !TAILQ_EMPTY ( &gListHead ) ) 748 { 749 750 SCSITaskLogEntry * entry = NULL; 751 752 entry = TAILQ_FIRST ( &gListHead ); 753 while ( entry != NULL ) 754 { 755 756 if ( entry->taskID == gTraceBuffer[index].arg2 ) 757 { 758 759 entry->cdb[ 8] = gTraceBuffer[index].arg3 & 0xFF; 760 entry->cdb[ 9] = ( gTraceBuffer[index].arg3 >> 8 ) & 0xFF; 761 entry->cdb[10] = ( gTraceBuffer[index].arg3 >> 16 ) & 0xFF; 762 entry->cdb[11] = ( gTraceBuffer[index].arg3 >> 24 ) & 0xFF; 763 entry->cdb[12] = gTraceBuffer[index].arg4 & 0xFF; 764 entry->cdb[13] = ( gTraceBuffer[index].arg4 >> 8 ) & 0xFF; 765 entry->cdb[14] = ( gTraceBuffer[index].arg4 >> 16 ) & 0xFF; 766 entry->cdb[15] = ( gTraceBuffer[index].arg4 >> 24 ) & 0xFF; 767 768 printf ( "%-8.8s Request: %02X %02X %02X %02X %02X %02X %02X %02X %02X %02X %02X %02X %02X %02X %02X %02X\n", 769 &( ctime ( ¤tTime )[11] ), 770 entry->cdb[ 0], entry->cdb[ 1], entry->cdb[ 2], entry->cdb[ 3], 771 entry->cdb[ 4], entry->cdb[ 5], entry->cdb[ 6], entry->cdb[ 7], 772 entry->cdb[ 8], entry->cdb[ 9], entry->cdb[10], entry->cdb[11], 773 entry->cdb[12], entry->cdb[13], entry->cdb[14], entry->cdb[15] ); 774 775 } 776 777 entry = TAILQ_NEXT ( entry, chain ); 778 779 } 780 781 } 782 783 } 784 break; 785 786 case kSCSITaskTracePointResponseLog1Code: 787 { 788 789 // If this isn't asked for, don't do any work. 790 if ( ( gPrintfMask & ( 1 << kSAMClassSCSITask ) ) == 0 ) 791 continue; 792 793 if ( !TAILQ_EMPTY ( &gListHead ) ) 794 { 795 796 SCSITaskLogEntry * entry = NULL; 797 798 entry = TAILQ_FIRST ( &gListHead ); 799 while ( entry != NULL ) 800 { 801 802 if ( entry->taskID == gTraceBuffer[index].arg2 ) 803 { 804 805 printf ( "%-8.8s Response: serviceResponse = 0x%02X, taskStatus = 0x%02X\n", 806 &( ctime ( ¤tTime )[11] ), 807 ( unsigned int ) gTraceBuffer[index].arg3 & 0xFF, 808 ( unsigned int ) ( gTraceBuffer[index].arg3 >> 8 ) & 0xFF ); 809 810 break; 811 812 } 813 814 entry = TAILQ_NEXT ( entry, chain ); 815 816 } 817 818 } 819 820 } 821 break; 822 823 case kSCSITaskTracePointResponseLog2Code: 824 { 825 826 // If this isn't asked for, don't do any work. 827 if ( ( gPrintfMask & ( 1 << kSAMClassSCSITask ) ) == 0 ) 828 continue; 829 830 fflush ( stdout ); 831 832 if ( !TAILQ_EMPTY ( &gListHead ) ) 833 { 834 835 SCSITaskLogEntry * entry = NULL; 836 837 entry = TAILQ_FIRST ( &gListHead ); 838 while ( entry != NULL ) 839 { 840 841 if ( entry->taskID == gTraceBuffer[index].arg2 ) 842 { 843 844 if ( gTraceBuffer[index].arg4 & kSenseDataValidMask ) 845 { 846 847 printf ( "%-8.8s Response: serviceResponse = %d, taskStatus = %d, senseKey = %d, ASC = 0x%02X, ASCQ = 0x%02X\n", 848 &( ctime ( ¤tTime )[11] ), 849 ( unsigned int ) gTraceBuffer[index].arg3 & 0xFF, 850 ( unsigned int ) ( gTraceBuffer[index].arg3 >> 8 ) & 0xFF, 851 ( unsigned int ) gTraceBuffer[index].arg4 & 0xFF, 852 ( unsigned int ) ( gTraceBuffer[index].arg4 >> 8 ) & 0xFF, 853 ( unsigned int ) ( gTraceBuffer[index].arg4 >> 16 ) & 0xFF ); 854 855 } 856 857 else 858 { 859 860 printf ( "%-8.8s Response: serviceResponse = 0x%02X, taskStatus = 0x%02X\n", 861 &( ctime ( ¤tTime )[11] ), 862 ( unsigned int ) gTraceBuffer[index].arg3 & 0xFF, 863 ( unsigned int ) ( gTraceBuffer[index].arg3 >> 8 ) & 0xFF ); 864 865 } 866 867 break; 868 869 } 870 871 entry = TAILQ_NEXT ( entry, chain ); 872 873 } 874 875 if ( entry != NULL ) 876 { 877 878 TAILQ_REMOVE ( &gListHead, entry, chain ); 879 free ( entry ); 880 881 } 882 883 } 884 885 } 886 break; 887 888 case kATADeviceInfoCode: 889 { 890 printf ( "%-8.8s ", &( ctime ( ¤tTime )[11] ) ); 891 printf ( "ATAPI start, obj = 0x%08X, UnitID = 0x%08X, Device Type = 0x%08X\n", 892 ( unsigned int ) gTraceBuffer[index].arg1, 893 ( unsigned int ) gTraceBuffer[index].arg2, 894 ( unsigned int ) gTraceBuffer[index].arg3 ); 895 } 896 break; 897 898 case kATASendSCSICommandCode: 899 { 900 901 printf ( "%-8.8s ", &( ctime ( ¤tTime )[11] ) ); 902 printf ( "ATAPI Send SCSI Command, obj = 0x%08X, UnitID = 0x%08X, cmd = 0x%08X, SCSITaskIdentifier = 0x%08X\n", 903 ( unsigned int ) gTraceBuffer[index].arg1, 904 ( unsigned int ) gTraceBuffer[index].arg2, 905 ( unsigned int ) gTraceBuffer[index].arg3, 906 ( unsigned int ) gTraceBuffer[index].arg4 ); 907 908 } 909 break; 910 911 case kATASendSCSICommandFailedCode: 912 { 913 printf ( "%-8.8s ", &( ctime ( ¤tTime )[11] ) ); 914 printf ( "ATAPI Send SCSI Command failed!, obj = 0x%08X, UnitID = 0x%08X, SCSITaskIdentifier = 0x%08X\n", 915 ( unsigned int ) gTraceBuffer[index].arg1, 916 ( unsigned int ) gTraceBuffer[index].arg2, 917 ( unsigned int ) gTraceBuffer[index].arg3 ); 918 } 919 break; 920 921 case kATACompleteSCSICommandCode: 922 { 923 924 printf ( "%-8.8s ", &( ctime ( ¤tTime )[11] ) ); 925 printf ( "ATAPI Complete SCSI Command, obj = 0x%08X, UnitID = 0x%08X, SCSITaskIdentifier = 0x%08X, serviceResponse = 0x%02X, taskStatus = 0x%02X\n", 926 ( unsigned int ) gTraceBuffer[index].arg1, 927 ( unsigned int ) gTraceBuffer[index].arg2, 928 ( unsigned int ) gTraceBuffer[index].arg3, 929 ( unsigned int ) ( gTraceBuffer[index].arg4 >> 8 ) & 0xFF, 930 ( unsigned int ) gTraceBuffer[index].arg4 & 0xFF ); 931 932 } 933 break; 934 935 case kATAAbortCode: 936 { 937 938 printf ( "%-8.8s ", &( ctime ( ¤tTime )[11] ) ); 939 printf ( "ATAPI Abort, obj = 0x%08X, UnitID = 0x%08X, SCSITaskIdentifier = 0x%08X\n", 940 ( unsigned int ) gTraceBuffer[index].arg1, 941 ( unsigned int ) gTraceBuffer[index].arg2, 942 ( unsigned int ) gTraceBuffer[index].arg3 ); 943 944 } 945 break; 946 947 case kATAPowerOnResetCode: 948 { 949 950 printf ( "%-8.8s ", &( ctime ( ¤tTime )[11] ) ); 951 printf ( "ATAPI Resetting device at Handle Power On, obj = 0x%08X, UnitID = 0x%08X Device Type = 0x%08X\n", 952 ( unsigned int ) gTraceBuffer[index].arg1, 953 ( unsigned int ) gTraceBuffer[index].arg2, 954 ( unsigned int ) gTraceBuffer[index].arg3 ); 955 956 } 957 break; 958 959 case kATAPowerOnNoResetCode: 960 { 961 962 printf ( "%-8.8s ", &( ctime ( ¤tTime )[11] ) ); 963 printf ( "ATAPI Not resetting device at Handle Power On, obj = 0x%08X, UnitID = 0x%08X Device Type = 0x%08X\n", 964 ( unsigned int ) gTraceBuffer[index].arg1, 965 ( unsigned int ) gTraceBuffer[index].arg2, 966 ( unsigned int ) gTraceBuffer[index].arg3 ); 967 968 } 969 break; 970 971 case kATAHandlePowerOffCode: 972 { 973 974 printf ( "%-8.8s ", &( ctime ( ¤tTime )[11] ) ); 975 printf ( "ATAPI Handle Power Off, obj = 0x%08X, UnitID = 0x%08X Device Type = 0x%08X\n", 976 ( unsigned int ) gTraceBuffer[index].arg1, 977 ( unsigned int ) gTraceBuffer[index].arg2, 978 ( unsigned int ) gTraceBuffer[index].arg3 ); 979 980 } 981 break; 982 983 case kATAResetCompleteCode: 984 { 985 986 printf ( "%-8.8s ", &( ctime ( ¤tTime )[11] ) ); 987 printf ( "ATAPI Reset complete, UnitID = 0x%08X\n", 988 ( unsigned int ) gTraceBuffer[index].arg1 ); 989 990 } 991 break; 992 993 case kATAResetCode: 994 { 995 996 printf ( "%-8.8s ", &( ctime ( ¤tTime )[11] ) ); 997 printf ( "ATAPI Device Reset, obj = 0x%08X, UnitID = 0x%08X\n", 998 ( unsigned int ) gTraceBuffer[index].arg1, 999 ( unsigned int ) gTraceBuffer[index].arg2 ); 1000 1001 } 1002 break; 1003 1004 case kATADriverPowerOff: 1005 { 1006 1007 printf ( "%-8.8s ", &( ctime ( ¤tTime )[11] ) ); 1008 printf ( "ATAPI Driver Power Off, obj = 0x%08X, UnitID = 0x%08X, cmd = 0x%08X\n", 1009 ( unsigned int ) gTraceBuffer[index].arg1, 1010 ( unsigned int ) gTraceBuffer[index].arg2, 1011 ( unsigned int ) gTraceBuffer[index].arg3 ); 1012 1013 } 1014 break; 1015 1016 case kATAStartStatusPolling: 1017 { 1018 1019 printf ( "%-8.8s ", &( ctime ( ¤tTime )[11] ) ); 1020 printf ( "ATAPI Start polling Status Register, obj = 0x%08X, UnitID = 0x%08X, Device Type = 0x%08X\n", 1021 ( unsigned int ) gTraceBuffer[index].arg1, 1022 ( unsigned int ) gTraceBuffer[index].arg2, 1023 ( unsigned int ) gTraceBuffer[index].arg3 ); 1024 1025 } 1026 break; 1027 1028 case kATAStatusPoll: 1029 { 1030 1031 printf ( "%-8.8s ", &( ctime ( ¤tTime )[11] ) ); 1032 printf ( "ATAPI Polling Status Register, obj = 0x%08X, UnitID = 0x%08X, Device Type = 0x%08X\n", 1033 ( unsigned int ) gTraceBuffer[index].arg1, 1034 ( unsigned int ) gTraceBuffer[index].arg2, 1035 ( unsigned int ) gTraceBuffer[index].arg3 ); 1036 1037 } 1038 break; 1039 1040 case kATAStopStatusPolling: 1041 { 1042 1043 printf ( "%-8.8s ", &( ctime ( ¤tTime )[11] ) ); 1044 printf ( "ATAPI Stop polling Status Register, obj = 0x%08X, UnitID = 0x%08X, Device Type = 0x%08X\n", 1045 ( unsigned int ) gTraceBuffer[index].arg1, 1046 ( unsigned int ) gTraceBuffer[index].arg2, 1047 ( unsigned int ) gTraceBuffer[index].arg3 ); 1048 1049 } 1050 break; 1051 1052 case kATASendATASleepCmd: 1053 { 1054 1055 printf ( "%-8.8s ", &( ctime ( ¤tTime )[11] ) ); 1056 printf ( "ATAPI Send ATA Sleep Command, obj = 0x%08X, UnitID = 0x%08X, cmd = Device Type = 0x%08X\n", 1057 ( unsigned int ) gTraceBuffer[index].arg1, 1058 ( unsigned int ) gTraceBuffer[index].arg2, 1059 ( unsigned int ) gTraceBuffer[index].arg3 ); 1060 1061 } 1062 break; 1063 1064 default: 1065 { 1066 continue; 1067 } 1068 break; 1069 1070 } 1071 1072 } 1073 1074 fflush ( 0 ); 1075 1076} 1077 1078 1079//----------------------------------------------------------------------------- 1080// LoadATAPIExtension 1081//----------------------------------------------------------------------------- 1082 1083static void 1084LoadATAPIExtension ( void ) 1085{ 1086 1087 posix_spawn_file_actions_t fileActions; 1088 char argv0 [] = "/sbin/kextload"; 1089 char argv1 [] = "/System/Library/Extensions/IOATAFamily.kext/Contents/PlugIns/IOATAPIProtocolTransport.kext"; 1090 char * const argv[] = { argv0, argv1, NULL }; 1091 char * const env[] = { NULL }; 1092 pid_t child = 0; 1093 union wait status; 1094 1095 posix_spawn_file_actions_init ( &fileActions ); 1096 posix_spawn_file_actions_addclose ( &fileActions, STDOUT_FILENO ); 1097 posix_spawn_file_actions_addclose ( &fileActions, STDERR_FILENO ); 1098 1099 posix_spawn ( &child, "/sbin/kextload", &fileActions, NULL, argv, env ); 1100 1101 if ( !( ( wait4 ( child, ( int * ) &status, 0, NULL ) == child ) && ( WIFEXITED ( status ) ) ) ) 1102 { 1103 printf ( "Error loading ATAPI extension\n" ); 1104 } 1105 1106 posix_spawn_file_actions_destroy ( &fileActions ); 1107 1108} 1109 1110 1111//----------------------------------------------------------------------------- 1112// Quit 1113//----------------------------------------------------------------------------- 1114 1115static void 1116Quit ( const char * s ) 1117{ 1118 1119 if ( gTraceEnabled == TRUE ) 1120 EnableTraceBuffer ( 0 ); 1121 1122 if ( gSetRemoveFlag == TRUE ) 1123 RemoveTraceBuffer ( ); 1124 1125 ResetDebugFlags ( ); 1126 1127 fprintf ( stderr, "%s: ", gProgramName ); 1128 if ( s != NULL ) 1129 { 1130 fprintf ( stderr, "%s", s ); 1131 } 1132 1133 fprintf ( stderr, "\n" ); 1134 1135 exit ( 1 ); 1136 1137} 1138 1139 1140//----------------------------------------------------------------------------- 1141// ResetDebugFlags 1142//----------------------------------------------------------------------------- 1143 1144static void 1145ResetDebugFlags ( void ) 1146{ 1147 1148 SAMSysctlArgs samArgs; 1149 ATAPISysctlArgs atapiArgs; 1150 int error; 1151 1152 samArgs.type = kSAMTypeDebug; 1153 samArgs.operation = kSAMOperationSetFlags; 1154 samArgs.validBits = kSAMTraceFlagsValidMask; 1155 samArgs.samDebugFlags = 0; 1156 samArgs.samTraceFlags = gSavedSAMTraceMask; 1157 1158 error = sysctlbyname ( SAM_SYSCTL, NULL, NULL, &samArgs, sizeof ( samArgs ) ); 1159 1160 atapiArgs.type = kATAPITypeDebug; 1161 atapiArgs.operation = kATAPIOperationSetFlags; 1162 atapiArgs.debugFlags = gSavedATAPIDebugMask; 1163 1164 error = sysctlbyname ( ATAPI_SYSCTL, NULL, NULL, &atapiArgs, sizeof ( atapiArgs ) ); 1165 1166} 1167 1168 1169//----------------------------------------------------------------------------- 1170// GetDivisor 1171//----------------------------------------------------------------------------- 1172 1173static void 1174GetDivisor ( void ) 1175{ 1176 1177 struct mach_timebase_info mti; 1178 1179 mach_timebase_info ( &mti ); 1180 1181 gDivisor = ( ( double ) mti.denom / ( double ) mti.numer) * 1000; 1182 1183} 1184