debug.c

WinAoE is an open source GPLv3 driver for using AoE (ATA over Ethernet) on Microsoft Windows

/*
  Copyright 2006-2008, V.
  For contact information, see http://winaoe.org/

  This file is part of WinAoE.

  WinAoE is free software: you can redistribute it and/or modify
  it under the terms of the GNU General Public License as published by
  the Free Software Foundation, either version 3 of the License, or
  (at your option) any later version.

  WinAoE is distributed in the hope that it will be useful,
  but WITHOUT ANY WARRANTY; without even the implied warranty of
  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  GNU General Public License for more details.

  You should have received a copy of the GNU General Public License
  along with WinAoE.  If not, see <http://www.gnu.org/licenses/>.
*/

#include "portable.h"
#include <ntddk.h>
#include <srb.h>
#include <scsi.h>
#include <ntddscsi.h>
#include <ntddstor.h>
#include <ntdddisk.h>
#include <ndis.h>
#include "driver.h"
#include "mount.h"

typedef struct _IRPLIST {
  PIRP Irp;
  ULONG Number;
  PCHAR DebugMessage;
  struct _IRPLIST *Next;
  struct _IRPLIST *Previous;
} IRPLIST, *PIRPLIST;

PIRPLIST IrpList = NULL;
KSPIN_LOCK SpinLock;
ULONG Number = 0;

extern int sprintf(char*, const char *, ...);

// in this file
PIRPLIST STDCALL IrpListRecord(IN PIRP Irp);
VOID STDCALL DecodeIrp(IN PDEVICE_OBJECT DeviceObject, IN PIRP Irp, IN PCHAR DebugMessage);
PCHAR STDCALL MajorFunctionString(IN UCHAR MajorFunction);
PCHAR STDCALL PnPMinorFunctionString(IN UCHAR MinorFunction);
PCHAR STDCALL SystemControlMinorFunctionString(IN UCHAR MinorFunction);
PCHAR STDCALL PowerMinorFunctionString(IN UCHAR MinorFunction);
PCHAR STDCALL QueryDeviceRelationsString(IN DEVICE_RELATION_TYPE Type);
PCHAR STDCALL QueryIdString(IN BUS_QUERY_ID_TYPE IdType);
PCHAR STDCALL SrbFunctionString(IN UCHAR Function);
PCHAR STDCALL DeviceIoControlString(IN ULONG IoControlCode);
PCHAR STDCALL DeviceTextTypeString(IN DEVICE_TEXT_TYPE DeviceTextType);
PCHAR STDCALL SCSIOPString(IN UCHAR OperationCode);

VOID STDCALL InitializeDebug() {
  KeInitializeSpinLock(&SpinLock);
}

PIRPLIST STDCALL IrpListRecord(IN PIRP Irp) {
  PIRPLIST Record;
  KIRQL Irql;

  KeAcquireSpinLock(&SpinLock, &Irql);
  Record = IrpList;
  while (Record != NULL && Record->Irp != Irp) Record = Record->Next;
  KeReleaseSpinLock(&SpinLock, Irql);
  return Record;
}

VOID STDCALL DebugIrpStart(IN PDEVICE_OBJECT DeviceObject, IN PIRP Irp) {
  PCHAR DebugMessage;
  PIRPLIST Record, Temp;
  KIRQL Irql;

  if ((DebugMessage = (PCHAR)ExAllocatePool(NonPagedPool, 1024)) == NULL) {
    DbgPrint("DebugIrpStart ExAllocatePool DebugMessage\n");
  }
  DecodeIrp(DeviceObject, Irp, DebugMessage);
  if ((Record = (PIRPLIST)ExAllocatePool(NonPagedPool, sizeof(IRPLIST))) == NULL) {
    DbgPrint("DebugIrpStart ExAllocatePool Record\n");
    DbgPrint("IRP %s\n", DebugMessage);
  }
  Record->Next = NULL;
  Record->Previous = NULL;
  Record->Irp = Irp;
  Record->DebugMessage = DebugMessage;
  Record->Number = InterlockedIncrement(&Number);;
  KeAcquireSpinLock(&SpinLock, &Irql);
  if (IrpList == NULL) {
    IrpList = Record;
    Record->Previous = NULL;
  } else {
    Temp = IrpList;
    while (Temp->Next != NULL) Temp = Temp->Next;
    Temp->Next = Record;
    Record->Previous = Temp;
  }
  KeReleaseSpinLock(&SpinLock, Irql);
  DbgPrint("IRP %d: %s\n", Record->Number, Record->DebugMessage);
}

VOID STDCALL DebugIrpEnd(IN PIRP Irp, IN NTSTATUS Status) {
  PIRPLIST Record;
  KIRQL Irql;

  if ((Record = IrpListRecord(Irp)) == NULL) {
    DbgPrint("Irp not found in IrpList!! (returned 0x%08x, Status)\n");
    return;
  }
  // There is no race condition between getting the record and unlinking in IrpList, unless DebugIrpEnd
  // is called more than once on an irp (which itself is a bug, it should only be called one time).
  KeAcquireSpinLock(&SpinLock, &Irql);
  if (Record->Previous == NULL) {
    IrpList = Record->Next;
  } else {
    Record->Previous->Next = Record->Next;
  }
  if (Record->Next != NULL) {
    Record->Next->Previous = Record->Previous;
  }
  KeReleaseSpinLock(&SpinLock, Irql);

  DbgPrint("IRP %d: %s -> 0x%08x\n", Record->Number, Record->DebugMessage, Status);
  ExFreePool(Record->DebugMessage);
  ExFreePool(Record);
}

VOID STDCALL DecodeIrp(IN PDEVICE_OBJECT DeviceObject, IN PIRP Irp, IN PCHAR DebugMessage) {
  PDEVICEEXTENSION DeviceExtension = (PDEVICEEXTENSION)DeviceObject->DeviceExtension;
  PIO_STACK_LOCATION Stack = IoGetCurrentIrpStackLocation(Irp);
  PSCSI_REQUEST_BLOCK Srb;
  PCDB Cdb;
  ULONG StartSector, SectorCount;
  PSTORAGE_PROPERTY_QUERY StoragePropertyQuery;

  sprintf(DebugMessage, "%s %s", (DeviceExtension->IsBus?"Bus":"Disk"), MajorFunctionString(Stack->MajorFunction));
  switch (Stack->MajorFunction) {
    case IRP_MJ_SYSTEM_CONTROL:
      sprintf(DebugMessage, "%s %s", DebugMessage, SystemControlMinorFunctionString(Stack->MinorFunction));
      break;
    case IRP_MJ_PNP:
      sprintf(DebugMessage, "%s %s", DebugMessage, PnPMinorFunctionString(Stack->MinorFunction));
      switch (Stack->MinorFunction) {
        case IRP_MN_QUERY_ID:
          sprintf(DebugMessage, "%s %s", DebugMessage, QueryIdString(Stack->Parameters.QueryId.IdType));
          break;
        case IRP_MN_QUERY_DEVICE_TEXT:
          sprintf(DebugMessage, "%s %s", DebugMessage, DeviceTextTypeString(Stack->Parameters.QueryDeviceText.DeviceTextType));
          break;
        case IRP_MN_QUERY_DEVICE_RELATIONS:
          sprintf(DebugMessage, "%s %s", DebugMessage, QueryDeviceRelationsString(Stack->Parameters.QueryDeviceRelations.Type));
          break;
      }
      break;
    case IRP_MJ_DEVICE_CONTROL:
      sprintf(DebugMessage, "%s (0x%08x) %s", DebugMessage, (int)Stack->Parameters.DeviceIoControl.IoControlCode, DeviceIoControlString(Stack->Parameters.DeviceIoControl.IoControlCode));
      if (!DeviceExtension->IsBus && Stack->Parameters.DeviceIoControl.IoControlCode == IOCTL_STORAGE_QUERY_PROPERTY) {
        StoragePropertyQuery = Irp->AssociatedIrp.SystemBuffer;
        switch (StoragePropertyQuery->PropertyId) {
          case StorageDeviceProperty:  sprintf(DebugMessage, "%s StorageDeviceProperty", DebugMessage); break;
          case StorageAdapterProperty: sprintf(DebugMessage, "%s StorageAdapterProperty", DebugMessage); break;
          default:                     sprintf(DebugMessage, "%s StorageUnknownProperty (%d)", DebugMessage, StoragePropertyQuery->PropertyId);
        }
        switch (StoragePropertyQuery->QueryType) {
          case PropertyStandardQuery: sprintf(DebugMessage, "%s PropertyStandardQuery", DebugMessage); break;
          case PropertyExistsQuery:   sprintf(DebugMessage, "%s PropertyExistsQuery", DebugMessage); break;
          default:                    sprintf(DebugMessage, "%s PropertyUnknownQuery (%d)", DebugMessage, StoragePropertyQuery->QueryType);
        }
      }
      break;
    case IRP_MJ_SCSI:
      if (!DeviceExtension->IsBus) {
        Srb = Stack->Parameters.Scsi.Srb;
        Cdb = (PCDB)Srb->Cdb;
        sprintf(DebugMessage, "%s %s", DebugMessage, SrbFunctionString(Srb->Function));
        if (Srb->Lun == 0 && Srb->Function == SRB_FUNCTION_EXECUTE_SCSI) {
          sprintf(DebugMessage, "%s %s", DebugMessage, SCSIOPString(Cdb->AsByte[0]));
          if (Cdb->AsByte[0] == SCSIOP_READ || Cdb->AsByte[0] == SCSIOP_WRITE || Cdb->AsByte[0] == SCSIOP_VERIFY) {
            StartSector = (Cdb->CDB10.LogicalBlockByte0 << 24) + (Cdb->CDB10.LogicalBlockByte1 << 16) + (Cdb->CDB10.LogicalBlockByte2 << 8) + Cdb->CDB10.LogicalBlockByte3;
            SectorCount = (Cdb->CDB10.TransferBlocksMsb << 8 ) + Cdb->CDB10.TransferBlocksLsb;
            sprintf(DebugMessage, "%s %d %d", DebugMessage, (int)StartSector, (int)SectorCount);
          }
          if (Cdb->AsByte[0] == SCSIOP_READ || Cdb->AsByte[0] == SCSIOP_WRITE) {
            sprintf(DebugMessage, "%s (buffersize: %d)", DebugMessage, (int)Srb->DataTransferLength);
          }
        }
      }
      break;
  }
}

PCHAR STDCALL MajorFunctionString(IN UCHAR MajorFunction) {
  switch (MajorFunction) {
    case IRP_MJ_CREATE:                   return "CREATE";
//    case IRP_MJ_NAMED_PIPE:               return "NAMED_PIPE";
    case IRP_MJ_CLOSE:                    return "CLOSE";
    case IRP_MJ_READ:                     return "READ";
    case IRP_MJ_WRITE:                    return "WRITE";
    case IRP_MJ_QUERY_INFORMATION:        return "QUERY_INFORMATION";
    case IRP_MJ_SET_INFORMATION:          return "SET_INFORMATION";
    case IRP_MJ_QUERY_EA:                 return "QUERY_EA";
    case IRP_MJ_SET_EA:                   return "SET_EA";
    case IRP_MJ_FLUSH_BUFFERS:            return "FLUSH_BUFFERS";
    case IRP_MJ_QUERY_VOLUME_INFORMATION: return "QUERY_VOLUME_INFORMATION";
    case IRP_MJ_SET_VOLUME_INFORMATION:   return "SET_VOLUME_INFORMATION";
    case IRP_MJ_DIRECTORY_CONTROL:        return "DIRECTORY_CONTROL";
    case IRP_MJ_FILE_SYSTEM_CONTROL:      return "FILE_SYSTEM_CONTROL";
    case IRP_MJ_DEVICE_CONTROL:           return "DEVICE_CONTROL";
//    case IRP_MJ_INTERNAL_DEVICE_CONTROL:  return "INTERNAL_DEVICE_CONTROL";
    case IRP_MJ_SCSI:                     return "SCSI";
    case IRP_MJ_SHUTDOWN:                 return "SHUTDOWN";