/** * ZuluSCSI™ - Copyright (c) 2022 Rabbit Hole Computing™ * * ZuluSCSI™ firmware is licensed under the GPL version 3 or any later version.  * * https://www.gnu.org/licenses/gpl-3.0.html * ---- * This program 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.  * * This program 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 this program.  If not, see . **/ // SCSI trace logging #include "ZuluSCSI_log_trace.h" #include "ZuluSCSI_log.h" #include extern "C" { #include #include } static bool g_LogData = false; static bool g_LogInitiatorCommand = false; static int g_InByteCount = 0; static int g_OutByteCount = 0; static uint16_t g_DataChecksum = 0; static const char *getCommandName(uint8_t cmd) { switch (cmd) { case 0x00: return "TestUnitReady"; case 0x01: return "RezeroUnit/Rewind"; case 0x03: return "RequestSense"; case 0x04: return "FormatUnit"; case 0x05: return "ReadBlockLimits"; case 0x08: return "Read6"; case 0x0A: return "Write6"; case 0x0B: return "Seek6"; case 0x0F: return "WriteSectorBuffer"; case 0x10: return "WriteFilemarks"; case 0x11: return "Space"; case 0x12: return "Inquiry"; case 0x13: return "Verify"; case 0x15: return "ModeSelect6"; case 0x16: return "Reserve"; case 0x17: return "Release"; case 0x19: return "Erase"; case 0x1A: return "ModeSense"; case 0x1B: return "StartStopUnit"; case 0x1C: return "ReceiveDiagnostic"; case 0x1D: return "SendDiagnostic"; case 0x1E: return "PreventAllowMediumRemoval"; case 0x25: return "ReadCapacity"; case 0x28: return "Read10"; case 0x2A: return "Write10"; case 0x2B: return "Seek10"; case 0x2C: return "Erase10"; case 0x2E: return "WriteVerify"; case 0x2F: return "Verify"; case 0x34: return "PreFetch/ReadPosition"; case 0x35: return "SynchronizeCache"; case 0x36: return "LockUnlockCache"; case 0x37: return "ReadDefectData"; case 0x3B: return "WriteBuffer"; case 0x3C: return "ReadBuffer"; case 0x42: return "CDROM Read SubChannel"; case 0x43: return "CDROM Read TOC"; case 0x44: return "CDROM Read Header"; case 0x46: return "CDROM GetConfiguration"; case 0x4A: return "GetEventStatusNotification"; case 0x4B: return "CDROM PauseResume"; case 0x4E: return "CDROM StopPlayScan"; case 0x51: return "CDROM ReadDiscInformation"; case 0x45: return "CDROM PlayAudio10"; case 0xA5: return "CDROM PlayAudio12"; case 0x47: return "CDROM PlayAudioMSF"; case 0x48: return "CDROM PauseResume"; case 0x52: return "CDROM ReadTrackInformation"; case 0xBB: return "CDROM SetCDSpeed"; case 0xBD: return "CDROM MechanismStatus"; case 0xBE: return "ReadCD"; case 0xB9: return "ReadCDMSF"; case 0x55: return "ModeSelect10"; case 0x5A: return "ModeSense10"; case 0xAC: return "Erase12"; case 0xA8: return "Read12"; case 0xC0: return "OMTI-5204 DefineFlexibleDiskFormat"; case 0xC2: return "OMTI-5204 AssignDiskParameters"; default: return "Unknown"; } } static void printNewPhase(int phase, bool initiator = false) { g_LogData = false; g_LogInitiatorCommand = false; if (!g_log_debug) { return; } switch(phase) { case BUS_FREE: dbgmsg("-- BUS_FREE"); break; case BUS_BUSY: dbgmsg("-- BUS_BUSY"); break; case ARBITRATION: dbgmsg("---- ARBITRATION"); break; case SELECTION: if (initiator) dbgmsg("---- SELECTION"); else dbgmsg("---- SELECTION: ", (int)(*SCSI_STS_SELECTED & 7)); break; case RESELECTION: dbgmsg("---- RESELECTION"); break; case STATUS: if (initiator) { dbgmsg("---- STATUS"); g_LogData = true; } else if (scsiDev.status == GOOD) { dbgmsg("---- STATUS: 0 GOOD"); } else if (scsiDev.status == CHECK_CONDITION && scsiDev.target) { dbgmsg("---- STATUS: 2 CHECK_CONDITION, sense ", (uint32_t)scsiDev.target->sense.asc); } else { dbgmsg("---- STATUS: ", (int)scsiDev.status); } break; case COMMAND: g_LogInitiatorCommand = initiator; g_LogData = true; break; case DATA_IN: if (!initiator && scsiDev.target->syncOffset > 0) dbgmsg("---- DATA_IN, syncOffset ", (int)scsiDev.target->syncOffset, " syncPeriod ", (int)scsiDev.target->syncPeriod); else dbgmsg("---- DATA_IN"); break; case DATA_OUT: if (!initiator && scsiDev.target->syncOffset > 0) dbgmsg("---- DATA_OUT, syncOffset ", (int)scsiDev.target->syncOffset, " syncPeriod ", (int)scsiDev.target->syncPeriod); else dbgmsg("---- DATA_OUT"); break; case MESSAGE_IN: dbgmsg("---- MESSAGE_IN"); g_LogData = true; break; case MESSAGE_OUT: dbgmsg("---- MESSAGE_OUT"); g_LogData = true; break; default: dbgmsg("---- PHASE: ", phase); break; } } void scsiLogPhaseChange(int new_phase) { static int old_scsi_id = 0; static int old_phase = BUS_FREE; static int old_sync_period = 0; if (new_phase != old_phase) { if (old_phase == DATA_IN || old_phase == DATA_OUT) { dbgmsg("---- Total IN: ", g_InByteCount, " OUT: ", g_OutByteCount, " CHECKSUM: ", (int)g_DataChecksum); } g_InByteCount = g_OutByteCount = 0; g_DataChecksum = 0; if (old_phase >= 0 && scsiDev.target != NULL && old_scsi_id == scsiDev.target->targetId && old_sync_period != scsiDev.target->syncPeriod) { // Add a log message when negotiated synchronous speed changes. int syncper = scsiDev.target->syncPeriod; int syncoff = scsiDev.target->syncOffset; if (syncper > 0) { int mbyte_per_s = (1000 + syncper * 2) / (syncper * 4); logmsg("SCSI ID ", (int)scsiDev.target->targetId, " negotiated synchronous mode ", mbyte_per_s, " MB/s ", "(period 4x", syncper, " ns, offset ", syncoff, " bytes)"); } else { logmsg("SCSI ID ", (int)scsiDev.target->targetId, " negotiated asynchronous mode ", "(period 4x", syncper, " ns, offset ", syncoff, " bytes)"); } } printNewPhase(new_phase); old_phase = new_phase; old_sync_period = scsiDev.target->syncPeriod; old_scsi_id = scsiDev.target->targetId; } } void scsiLogInitiatorPhaseChange(int new_phase) { static int old_phase = BUS_FREE; if (new_phase != old_phase) { if (old_phase == DATA_IN || old_phase == DATA_OUT) { dbgmsg("---- Total IN: ", g_InByteCount, " OUT: ", g_OutByteCount, " CHECKSUM: ", (int)g_DataChecksum); } g_InByteCount = g_OutByteCount = 0; g_DataChecksum = 0; printNewPhase(new_phase, true); old_phase = new_phase; } } void scsiLogDataIn(const uint8_t *buf, uint32_t length) { if (g_LogData) { dbgmsg("------ IN: ", bytearray(buf, length)); } if (g_log_debug) { // BSD checksum algorithm for (uint32_t i = 0; i < length; i++) { g_DataChecksum = (g_DataChecksum >> 1) + ((g_DataChecksum & 1) << 15); g_DataChecksum += buf[i]; } } g_InByteCount += length; } void scsiLogDataOut(const uint8_t *buf, uint32_t length) { if (buf == scsiDev.cdb || g_LogInitiatorCommand) { dbgmsg("---- COMMAND: ", getCommandName(buf[0])); } if (g_LogData) { dbgmsg("------ OUT: ", bytearray(buf, length)); } if (g_log_debug) { // BSD checksum algorithm for (uint32_t i = 0; i < length; i++) { g_DataChecksum = (g_DataChecksum >> 1) + ((g_DataChecksum & 1) << 15); g_DataChecksum += buf[i]; } } g_OutByteCount += length; }