From: Andrea Mondelli Date: Wed, 6 Mar 2019 15:50:48 +0000 (-0500) Subject: misc: Removed inconsistency in O3* debug msgs X-Git-Tag: v19.0.0.0~988 X-Git-Url: https://git.libre-soc.org/?a=commitdiff_plain;h=e13d6dc9c0d7a4ae0215f1ee6793eb32570c5169;p=gem5.git misc: Removed inconsistency in O3* debug msgs Added consistency in the DEBUG message form, to allow a better parsing. Fixed sn/tid type parameter. Removed some annoying newlines Change-Id: I4761c49fc12b874a7d8b46779475b606865cad4b Reviewed-on: https://gem5-review.googlesource.com/c/public/gem5/+/17248 Reviewed-by: Jason Lowe-Power Maintainer: Jason Lowe-Power --- diff --git a/src/arch/mips/isa.cc b/src/arch/mips/isa.cc index 2711712fe..eaee294c8 100644 --- a/src/arch/mips/isa.cc +++ b/src/arch/mips/isa.cc @@ -450,7 +450,7 @@ ISA::setMiscRegNoEffect(int misc_reg, RegVal val, ThreadID tid) unsigned reg_sel = (bankType[misc_reg] == perThreadContext) ? tid : getVPENum(tid); DPRINTF(MipsPRA, - "[tid:%i]: Setting (direct set) CP0 Register:%u " + "[tid:%i] Setting (direct set) CP0 Register:%u " "Select:%u (%s) to %#x.\n", tid, misc_reg / 8, misc_reg % 8, miscRegNames[misc_reg], val); @@ -463,7 +463,7 @@ ISA::setRegMask(int misc_reg, RegVal val, ThreadID tid) unsigned reg_sel = (bankType[misc_reg] == perThreadContext) ? tid : getVPENum(tid); DPRINTF(MipsPRA, - "[tid:%i]: Setting CP0 Register: %u Select: %u (%s) to %#x\n", + "[tid:%i] Setting CP0 Register: %u Select: %u (%s) to %#x\n", tid, misc_reg / 8, misc_reg % 8, miscRegNames[misc_reg], val); miscRegFile_WriteMask[misc_reg][reg_sel] = val; } @@ -479,7 +479,7 @@ ISA::setMiscReg(int misc_reg, RegVal val, ThreadContext *tc, ThreadID tid) ? tid : getVPENum(tid); DPRINTF(MipsPRA, - "[tid:%i]: Setting CP0 Register:%u " + "[tid:%i] Setting CP0 Register:%u " "Select:%u (%s) to %#x, with effect.\n", tid, misc_reg / 8, misc_reg % 8, miscRegNames[misc_reg], val); diff --git a/src/cpu/o3/commit_impl.hh b/src/cpu/o3/commit_impl.hh index ec3d61050..2aa9d7824 100644 --- a/src/cpu/o3/commit_impl.hh +++ b/src/cpu/o3/commit_impl.hh @@ -644,7 +644,7 @@ template void DefaultCommit::squashAfter(ThreadID tid, const DynInstPtr &head_inst) { - DPRINTF(Commit, "Executing squash after for [tid:%i] inst [sn:%lli]\n", + DPRINTF(Commit, "Executing squash after for [tid:%i] inst [sn:%llu]\n", tid, head_inst->seqNum); assert(!squashAfterInst[tid] || squashAfterInst[tid] == head_inst); @@ -679,7 +679,7 @@ DefaultCommit::tick() if (rob->isDoneSquashing(tid)) { commitStatus[tid] = Running; } else { - DPRINTF(Commit,"[tid:%u]: Still Squashing, cannot commit any" + DPRINTF(Commit,"[tid:%i] Still Squashing, cannot commit any" " insts this cycle.\n", tid); rob->doSquash(tid); toIEW->commitInfo[tid].robSquashing = true; @@ -704,7 +704,7 @@ DefaultCommit::tick() const DynInstPtr &inst M5_VAR_USED = rob->readHeadInst(tid); - DPRINTF(Commit,"[tid:%i]: Instruction [sn:%lli] PC %s is head of" + DPRINTF(Commit,"[tid:%i] Instruction [sn:%llu] PC %s is head of" " ROB and ready to commit\n", tid, inst->seqNum, inst->pcState()); @@ -713,12 +713,12 @@ DefaultCommit::tick() ppCommitStall->notify(inst); - DPRINTF(Commit,"[tid:%i]: Can't commit, Instruction [sn:%lli] PC " + DPRINTF(Commit,"[tid:%i] Can't commit, Instruction [sn:%llu] PC " "%s is head of ROB and not ready\n", tid, inst->seqNum, inst->pcState()); } - DPRINTF(Commit, "[tid:%i]: ROB has %d insts & %d free entries.\n", + DPRINTF(Commit, "[tid:%i] ROB has %d insts & %d free entries.\n", tid, rob->countInsts(tid), rob->numFreeEntries(tid)); } @@ -862,17 +862,18 @@ DefaultCommit::commit() if (fromIEW->mispredictInst[tid]) { DPRINTF(Commit, - "[tid:%i]: Squashing due to branch mispred PC:%#x [sn:%i]\n", + "[tid:%i] Squashing due to branch mispred " + "PC:%#x [sn:%llu]\n", tid, fromIEW->mispredictInst[tid]->instAddr(), fromIEW->squashedSeqNum[tid]); } else { DPRINTF(Commit, - "[tid:%i]: Squashing due to order violation [sn:%i]\n", + "[tid:%i] Squashing due to order violation [sn:%llu]\n", tid, fromIEW->squashedSeqNum[tid]); } - DPRINTF(Commit, "[tid:%i]: Redirecting to PC %#x\n", + DPRINTF(Commit, "[tid:%i] Redirecting to PC %#x\n", tid, fromIEW->pc[tid].nextInstAddr()); @@ -1010,8 +1011,9 @@ DefaultCommit::commitInsts() assert(tid == commit_thread); - DPRINTF(Commit, "Trying to commit head instruction, [sn:%i] [tid:%i]\n", - head_inst->seqNum, tid); + DPRINTF(Commit, + "Trying to commit head instruction, [tid:%i] [sn:%llu]\n", + tid, head_inst->seqNum); // If the head instruction is squashed, it is ready to retire // (be removed from the ROB) at any time. @@ -1132,7 +1134,7 @@ DefaultCommit::commitInsts() squashAfter(tid, head_inst); } else { DPRINTF(Commit, "Unable to commit head instruction PC:%s " - "[tid:%i] [sn:%i].\n", + "[tid:%i] [sn:%llu].\n", head_inst->pcState(), tid ,head_inst->seqNum); break; } @@ -1169,12 +1171,17 @@ DefaultCommit::commitHead(const DynInstPtr &head_inst, unsigned inst_num) || head_inst->isAtomic() || (head_inst->isLoad() && head_inst->strictlyOrdered())); - DPRINTF(Commit, "Encountered a barrier or non-speculative " - "instruction [sn:%lli] at the head of the ROB, PC %s.\n", - head_inst->seqNum, head_inst->pcState()); + DPRINTF(Commit, + "Encountered a barrier or non-speculative " + "instruction [tid:%i] [sn:%llu] " + "at the head of the ROB, PC %s.\n", + tid, head_inst->seqNum, head_inst->pcState()); if (inst_num > 0 || iewStage->hasStoresToWB(tid)) { - DPRINTF(Commit, "Waiting for all stores to writeback.\n"); + DPRINTF(Commit, + "[tid:%i] [sn:%llu] " + "Waiting for all stores to writeback.\n", + tid, head_inst->seqNum); return false; } @@ -1185,8 +1192,9 @@ DefaultCommit::commitHead(const DynInstPtr &head_inst, unsigned inst_num) head_inst->clearCanCommit(); if (head_inst->isLoad() && head_inst->strictlyOrdered()) { - DPRINTF(Commit, "[sn:%lli]: Strictly ordered load, PC %s.\n", - head_inst->seqNum, head_inst->pcState()); + DPRINTF(Commit, "[tid:%i] [sn:%llu] " + "Strictly ordered load, PC %s.\n", + tid, head_inst->seqNum, head_inst->pcState()); toIEW->commitInfo[tid].strictlyOrdered = true; toIEW->commitInfo[tid].strictlyOrderedLoad = head_inst; } else { @@ -1210,11 +1218,14 @@ DefaultCommit::commitHead(const DynInstPtr &head_inst, unsigned inst_num) } if (inst_fault != NoFault) { - DPRINTF(Commit, "Inst [sn:%lli] PC %s has a fault\n", - head_inst->seqNum, head_inst->pcState()); + DPRINTF(Commit, "Inst [tid:%i] [sn:%llu] PC %s has a fault\n", + tid, head_inst->seqNum, head_inst->pcState()); if (iewStage->hasStoresToWB(tid) || inst_num > 0) { - DPRINTF(Commit, "Stores outstanding, fault must wait.\n"); + DPRINTF(Commit, + "[tid:%i] [sn:%llu] " + "Stores outstanding, fault must wait.\n", + tid, head_inst->seqNum); return false; } @@ -1249,8 +1260,9 @@ DefaultCommit::commitHead(const DynInstPtr &head_inst, unsigned inst_num) commitStatus[tid] = TrapPending; - DPRINTF(Commit, "Committing instruction with fault [sn:%lli]\n", - head_inst->seqNum); + DPRINTF(Commit, + "[tid:%i] [sn:%llu] Committing instruction with fault\n", + tid, head_inst->seqNum); if (head_inst->traceData) { if (DTRACE(ExecFaulting)) { head_inst->traceData->setFetchSeq(head_inst->seqNum); @@ -1284,8 +1296,9 @@ DefaultCommit::commitHead(const DynInstPtr &head_inst, unsigned inst_num) } } } - DPRINTF(Commit, "Committing instruction with [sn:%lli] PC %s\n", - head_inst->seqNum, head_inst->pcState()); + DPRINTF(Commit, + "[tid:%i] [sn:%llu] Committing instruction with PC %s\n", + tid, head_inst->seqNum, head_inst->pcState()); if (head_inst->traceData) { head_inst->traceData->setFetchSeq(head_inst->seqNum); head_inst->traceData->setCPSeq(thread[tid]->numOp); @@ -1294,8 +1307,9 @@ DefaultCommit::commitHead(const DynInstPtr &head_inst, unsigned inst_num) head_inst->traceData = NULL; } if (head_inst->isReturn()) { - DPRINTF(Commit,"Return Instruction Committed [sn:%lli] PC %s \n", - head_inst->seqNum, head_inst->pcState()); + DPRINTF(Commit, + "[tid:%i] [sn:%llu] Return Instruction Committed PC %s \n", + tid, head_inst->seqNum, head_inst->pcState()); } // Update the commit rename map @@ -1339,8 +1353,8 @@ DefaultCommit::getInsts() commitStatus[tid] != TrapPending) { changedROBNumEntries[tid] = true; - DPRINTF(Commit, "Inserting PC %s [sn:%i] [tid:%i] into ROB.\n", - inst->pcState(), inst->seqNum, tid); + DPRINTF(Commit, "[tid:%i] [sn:%llu] Inserting PC %s into ROB.\n", + inst->seqNum, tid, inst->pcState()); rob->insertInst(inst); @@ -1348,9 +1362,9 @@ DefaultCommit::getInsts() youngestSeqNum[tid] = inst->seqNum; } else { - DPRINTF(Commit, "Instruction PC %s [sn:%i] [tid:%i] was " - "squashed, skipping.\n", - inst->pcState(), inst->seqNum, tid); + DPRINTF(Commit, "[tid:%i] [sn:%llu] " + "Instruction PC %s was squashed, skipping.\n", + inst->seqNum, tid, inst->pcState()); } } } @@ -1364,7 +1378,7 @@ DefaultCommit::markCompletedInsts() for (int inst_num = 0; inst_num < fromIEW->size; ++inst_num) { assert(fromIEW->insts[inst_num]); if (!fromIEW->insts[inst_num]->isSquashed()) { - DPRINTF(Commit, "[tid:%i]: Marking PC %s, [sn:%lli] ready " + DPRINTF(Commit, "[tid:%i] Marking PC %s, [sn:%llu] ready " "within ROB.\n", fromIEW->insts[inst_num]->threadNumber, fromIEW->insts[inst_num]->pcState(), diff --git a/src/cpu/o3/cpu.cc b/src/cpu/o3/cpu.cc index 9da5b4359..621a6a409 100644 --- a/src/cpu/o3/cpu.cc +++ b/src/cpu/o3/cpu.cc @@ -689,11 +689,11 @@ FullO3CPU::activateThread(ThreadID tid) list::iterator isActive = std::find(activeThreads.begin(), activeThreads.end(), tid); - DPRINTF(O3CPU, "[tid:%i]: Calling activate thread.\n", tid); + DPRINTF(O3CPU, "[tid:%i] Calling activate thread.\n", tid); assert(!switchedOut()); if (isActive == activeThreads.end()) { - DPRINTF(O3CPU, "[tid:%i]: Adding to active threads list\n", + DPRINTF(O3CPU, "[tid:%i] Adding to active threads list\n", tid); activeThreads.push_back(tid); @@ -708,11 +708,11 @@ FullO3CPU::deactivateThread(ThreadID tid) list::iterator thread_it = std::find(activeThreads.begin(), activeThreads.end(), tid); - DPRINTF(O3CPU, "[tid:%i]: Calling deactivate thread.\n", tid); + DPRINTF(O3CPU, "[tid:%i] Calling deactivate thread.\n", tid); assert(!switchedOut()); if (thread_it != activeThreads.end()) { - DPRINTF(O3CPU,"[tid:%i]: Removing from active threads list\n", + DPRINTF(O3CPU,"[tid:%i] Removing from active threads list\n", tid); activeThreads.erase(thread_it); } @@ -790,7 +790,7 @@ template void FullO3CPU::suspendContext(ThreadID tid) { - DPRINTF(O3CPU,"[tid: %i]: Suspending Thread Context.\n", tid); + DPRINTF(O3CPU,"[tid:%i] Suspending Thread Context.\n", tid); assert(!switchedOut()); deactivateThread(tid); @@ -812,7 +812,7 @@ void FullO3CPU::haltContext(ThreadID tid) { //For now, this is the same as deallocate - DPRINTF(O3CPU,"[tid:%i]: Halt Context called. Deallocating\n", tid); + DPRINTF(O3CPU,"[tid:%i] Halt Context called. Deallocating\n", tid); assert(!switchedOut()); deactivateThread(tid); diff --git a/src/cpu/o3/decode_impl.hh b/src/cpu/o3/decode_impl.hh index 27b3c30a1..86f933992 100644 --- a/src/cpu/o3/decode_impl.hh +++ b/src/cpu/o3/decode_impl.hh @@ -238,7 +238,7 @@ DefaultDecode::checkStall(ThreadID tid) const bool ret_val = false; if (stalls[tid].rename) { - DPRINTF(Decode,"[tid:%i]: Stall fom Rename stage detected.\n", tid); + DPRINTF(Decode,"[tid:%i] Stall fom Rename stage detected.\n", tid); ret_val = true; } @@ -256,7 +256,7 @@ template bool DefaultDecode::block(ThreadID tid) { - DPRINTF(Decode, "[tid:%u]: Blocking.\n", tid); + DPRINTF(Decode, "[tid:%i] Blocking.\n", tid); // Add the current inputs to the skid buffer so they can be // reprocessed when this stage unblocks. @@ -288,7 +288,7 @@ DefaultDecode::unblock(ThreadID tid) { // Decode is done unblocking only if the skid buffer is empty. if (skidBuffer[tid].empty()) { - DPRINTF(Decode, "[tid:%u]: Done unblocking.\n", tid); + DPRINTF(Decode, "[tid:%i] Done unblocking.\n", tid); toFetch->decodeUnblock[tid] = true; wroteToTimeBuffer = true; @@ -296,7 +296,7 @@ DefaultDecode::unblock(ThreadID tid) return true; } - DPRINTF(Decode, "[tid:%u]: Currently unblocking.\n", tid); + DPRINTF(Decode, "[tid:%i] Currently unblocking.\n", tid); return false; } @@ -305,7 +305,7 @@ template void DefaultDecode::squash(const DynInstPtr &inst, ThreadID tid) { - DPRINTF(Decode, "[tid:%i]: [sn:%i] Squashing due to incorrect branch " + DPRINTF(Decode, "[tid:%i] [sn:%llu] Squashing due to incorrect branch " "prediction detected at decode.\n", tid, inst->seqNum); // Send back mispredict information. @@ -357,7 +357,7 @@ template unsigned DefaultDecode::squash(ThreadID tid) { - DPRINTF(Decode, "[tid:%i]: Squashing.\n",tid); + DPRINTF(Decode, "[tid:%i] Squashing.\n",tid); if (decodeStatus[tid] == Blocked || decodeStatus[tid] == Unblocking) { @@ -522,7 +522,7 @@ DefaultDecode::checkSignalsAndUpdate(ThreadID tid) // Check squash signals from commit. if (fromCommit->commitInfo[tid].squash) { - DPRINTF(Decode, "[tid:%u]: Squashing instructions due to squash " + DPRINTF(Decode, "[tid:%i] Squashing instructions due to squash " "from commit.\n", tid); squash(tid); @@ -535,7 +535,7 @@ DefaultDecode::checkSignalsAndUpdate(ThreadID tid) } if (decodeStatus[tid] == Blocked) { - DPRINTF(Decode, "[tid:%u]: Done blocking, switching to unblocking.\n", + DPRINTF(Decode, "[tid:%i] Done blocking, switching to unblocking.\n", tid); decodeStatus[tid] = Unblocking; @@ -548,7 +548,7 @@ DefaultDecode::checkSignalsAndUpdate(ThreadID tid) if (decodeStatus[tid] == Squashing) { // Switch status to running if decode isn't being told to block or // squash this cycle. - DPRINTF(Decode, "[tid:%u]: Done squashing, switching to running.\n", + DPRINTF(Decode, "[tid:%i] Done squashing, switching to running.\n", tid); decodeStatus[tid] = Running; @@ -618,7 +618,7 @@ DefaultDecode::decode(bool &status_change, ThreadID tid) // will allow, as long as it is not currently blocked. if (decodeStatus[tid] == Running || decodeStatus[tid] == Idle) { - DPRINTF(Decode, "[tid:%u]: Not blocked, so attempting to run " + DPRINTF(Decode, "[tid:%i] Not blocked, so attempting to run " "stage.\n",tid); decodeInsts(tid); @@ -652,13 +652,13 @@ DefaultDecode::decodeInsts(ThreadID tid) skidBuffer[tid].size() : insts[tid].size(); if (insts_available == 0) { - DPRINTF(Decode, "[tid:%u] Nothing to do, breaking out" + DPRINTF(Decode, "[tid:%i] Nothing to do, breaking out" " early.\n",tid); // Should I change the status to idle? ++decodeIdleCycles; return; } else if (decodeStatus[tid] == Unblocking) { - DPRINTF(Decode, "[tid:%u] Unblocking, removing insts from skid " + DPRINTF(Decode, "[tid:%i] Unblocking, removing insts from skid " "buffer.\n",tid); ++decodeUnblockCycles; } else if (decodeStatus[tid] == Running) { @@ -669,7 +669,7 @@ DefaultDecode::decodeInsts(ThreadID tid) &insts_to_decode = decodeStatus[tid] == Unblocking ? skidBuffer[tid] : insts[tid]; - DPRINTF(Decode, "[tid:%u]: Sending instruction to rename.\n",tid); + DPRINTF(Decode, "[tid:%i] Sending instruction to rename.\n",tid); while (insts_available > 0 && toRenameIndex < decodeWidth) { assert(!insts_to_decode.empty()); @@ -678,11 +678,11 @@ DefaultDecode::decodeInsts(ThreadID tid) insts_to_decode.pop(); - DPRINTF(Decode, "[tid:%u]: Processing instruction [sn:%lli] with " + DPRINTF(Decode, "[tid:%i] Processing instruction [sn:%lli] with " "PC %s\n", tid, inst->seqNum, inst->pcState()); if (inst->isSquashed()) { - DPRINTF(Decode, "[tid:%u]: Instruction %i with PC %s is " + DPRINTF(Decode, "[tid:%i] Instruction %i with PC %s is " "squashed, skipping.\n", tid, inst->seqNum, inst->pcState()); @@ -747,8 +747,10 @@ DefaultDecode::decodeInsts(ThreadID tid) squash(inst, inst->threadNumber); TheISA::PCState target = inst->branchTarget(); - DPRINTF(Decode, "[sn:%i]: Updating predictions: PredPC: %s\n", - inst->seqNum, target); + DPRINTF(Decode, + "[tid:%i] [sn:%llu] " + "Updating predictions: PredPC: %s\n", + tid, inst->seqNum, target); //The micro pc after an instruction level branch should be 0 inst->setPredTarg(target); break; diff --git a/src/cpu/o3/fetch_impl.hh b/src/cpu/o3/fetch_impl.hh index 8afe62335..8ef3b6ac1 100644 --- a/src/cpu/o3/fetch_impl.hh +++ b/src/cpu/o3/fetch_impl.hh @@ -387,7 +387,7 @@ DefaultFetch::processCacheCompletion(PacketPtr pkt) { ThreadID tid = cpu->contextToThread(pkt->req->contextId()); - DPRINTF(Fetch, "[tid:%u] Waking up from cache miss.\n", tid); + DPRINTF(Fetch, "[tid:%i] Waking up from cache miss.\n", tid); assert(!cpu->switchedOut()); // Only change the status if it's still waiting on the icache access @@ -406,7 +406,7 @@ DefaultFetch::processCacheCompletion(PacketPtr pkt) // this completion event). cpu->wakeCPU(); - DPRINTF(Activity, "[tid:%u] Activating fetch due to cache completion\n", + DPRINTF(Activity, "[tid:%i] Activating fetch due to cache completion\n", tid); switchToActive(); @@ -572,15 +572,18 @@ DefaultFetch::lookupAndUpdateNextPC( nextPC, tid); if (predict_taken) { - DPRINTF(Fetch, "[tid:%i]: [sn:%i]: Branch predicted to be taken to %s.\n", - tid, inst->seqNum, nextPC); + DPRINTF(Fetch, "[tid:%i] [sn:%llu] Branch at PC %#x " + "predicted to be taken to %s\n", + tid, inst->seqNum, inst->pcState().instAddr(), nextPC); } else { - DPRINTF(Fetch, "[tid:%i]: [sn:%i]:Branch predicted to be not taken.\n", - tid, inst->seqNum); + DPRINTF(Fetch, "[tid:%i] [sn:%llu] Branch at PC %#x " + "predicted to be not taken\n", + tid, inst->seqNum, inst->pcState().instAddr()); } - DPRINTF(Fetch, "[tid:%i]: [sn:%i] Branch predicted to go to %s.\n", - tid, inst->seqNum, nextPC); + DPRINTF(Fetch, "[tid:%i] [sn:%llu] Branch at PC %#x " + "predicted to go to %s\n", + tid, inst->seqNum, inst->pcState().instAddr(), nextPC); inst->setPredTarg(nextPC); inst->setPredTaken(predict_taken); @@ -699,8 +702,8 @@ DefaultFetch::finishTranslation(const Fault &fault, retryTid = tid; cacheBlocked = true; } else { - DPRINTF(Fetch, "[tid:%i]: Doing Icache access.\n", tid); - DPRINTF(Activity, "[tid:%i]: Activity: Waiting on I-cache " + DPRINTF(Fetch, "[tid:%i] Doing Icache access.\n", tid); + DPRINTF(Activity, "[tid:%i] Activity: Waiting on I-cache " "response.\n", tid); lastIcacheStall[tid] = curTick(); fetchStatus[tid] = IcacheWaitResponse; @@ -728,7 +731,7 @@ DefaultFetch::finishTranslation(const Fault &fault, // wake up is if a squash comes along and changes the PC. TheISA::PCState fetchPC = pc[tid]; - DPRINTF(Fetch, "[tid:%i]: Translation faulted, building noop.\n", tid); + DPRINTF(Fetch, "[tid:%i] Translation faulted, building noop.\n", tid); // We will use a nop in ordier to carry the fault. DynInstPtr instruction = buildInst(tid, StaticInst::nopStaticInstPtr, NULL, fetchPC, fetchPC, false); @@ -743,8 +746,8 @@ DefaultFetch::finishTranslation(const Fault &fault, fetchStatus[tid] = TrapPending; - DPRINTF(Fetch, "[tid:%i]: Blocked, need to handle the trap.\n", tid); - DPRINTF(Fetch, "[tid:%i]: fault (%s) detected @ PC %s.\n", + DPRINTF(Fetch, "[tid:%i] Blocked, need to handle the trap.\n", tid); + DPRINTF(Fetch, "[tid:%i] fault (%s) detected @ PC %s.\n", tid, fault->name(), pc[tid]); } _status = updateFetchStatus(); @@ -755,7 +758,7 @@ inline void DefaultFetch::doSquash(const TheISA::PCState &newPC, const DynInstPtr squashInst, ThreadID tid) { - DPRINTF(Fetch, "[tid:%i]: Squashing, setting PC to: %s.\n", + DPRINTF(Fetch, "[tid:%i] Squashing, setting PC to: %s.\n", tid, newPC); pc[tid] = newPC; @@ -768,11 +771,11 @@ DefaultFetch::doSquash(const TheISA::PCState &newPC, // Clear the icache miss if it's outstanding. if (fetchStatus[tid] == IcacheWaitResponse) { - DPRINTF(Fetch, "[tid:%i]: Squashing outstanding Icache miss.\n", + DPRINTF(Fetch, "[tid:%i] Squashing outstanding Icache miss.\n", tid); memReq[tid] = NULL; } else if (fetchStatus[tid] == ItlbWait) { - DPRINTF(Fetch, "[tid:%i]: Squashing outstanding ITLB miss.\n", + DPRINTF(Fetch, "[tid:%i] Squashing outstanding ITLB miss.\n", tid); memReq[tid] = NULL; } @@ -808,7 +811,7 @@ DefaultFetch::squashFromDecode(const TheISA::PCState &newPC, const DynInstPtr squashInst, const InstSeqNum seq_num, ThreadID tid) { - DPRINTF(Fetch, "[tid:%i]: Squashing from decode.\n", tid); + DPRINTF(Fetch, "[tid:%i] Squashing from decode.\n", tid); doSquash(newPC, squashInst, tid); @@ -825,7 +828,7 @@ DefaultFetch::checkStall(ThreadID tid) const if (stalls[tid].drain) { assert(cpu->isDraining()); - DPRINTF(Fetch,"[tid:%i]: Drain stall detected.\n",tid); + DPRINTF(Fetch,"[tid:%i] Drain stall detected.\n",tid); ret_val = true; } @@ -848,10 +851,10 @@ DefaultFetch::updateFetchStatus() fetchStatus[tid] == IcacheAccessComplete) { if (_status == Inactive) { - DPRINTF(Activity, "[tid:%i]: Activating stage.\n",tid); + DPRINTF(Activity, "[tid:%i] Activating stage.\n",tid); if (fetchStatus[tid] == IcacheAccessComplete) { - DPRINTF(Activity, "[tid:%i]: Activating fetch due to cache" + DPRINTF(Activity, "[tid:%i] Activating fetch due to cache" "completion\n",tid); } @@ -878,7 +881,7 @@ DefaultFetch::squash(const TheISA::PCState &newPC, const InstSeqNum seq_num, DynInstPtr squashInst, ThreadID tid) { - DPRINTF(Fetch, "[tid:%u]: Squash from commit.\n", tid); + DPRINTF(Fetch, "[tid:%i] Squash from commit.\n", tid); doSquash(newPC, squashInst, tid); @@ -962,8 +965,8 @@ DefaultFetch::tick() if (!stalls[tid].decode && !fetchQueue[tid].empty()) { const auto& inst = fetchQueue[tid].front(); toDecode->insts[toDecode->size++] = inst; - DPRINTF(Fetch, "[tid:%i][sn:%i]: Sending instruction to decode from " - "fetch queue. Fetch queue size: %i.\n", + DPRINTF(Fetch, "[tid:%i] [sn:%llu] Sending instruction to decode " + "from fetch queue. Fetch queue size: %i.\n", tid, inst->seqNum, fetchQueue[tid].size()); wroteToTimeBuffer = true; @@ -1006,7 +1009,7 @@ DefaultFetch::checkSignalsAndUpdate(ThreadID tid) // Check squash signals from commit. if (fromCommit->commitInfo[tid].squash) { - DPRINTF(Fetch, "[tid:%u]: Squashing instructions due to squash " + DPRINTF(Fetch, "[tid:%i] Squashing instructions due to squash " "from commit.\n",tid); // In any case, squash. squash(fromCommit->commitInfo[tid].pc, @@ -1036,7 +1039,7 @@ DefaultFetch::checkSignalsAndUpdate(ThreadID tid) // Check squash signals from decode. if (fromDecode->decodeInfo[tid].squash) { - DPRINTF(Fetch, "[tid:%u]: Squashing instructions due to squash " + DPRINTF(Fetch, "[tid:%i] Squashing instructions due to squash " "from decode.\n",tid); // Update the branch predictor. @@ -1069,7 +1072,7 @@ DefaultFetch::checkSignalsAndUpdate(ThreadID tid) fetchStatus[tid] != IcacheWaitRetry && fetchStatus[tid] != ItlbWait && fetchStatus[tid] != QuiescePending) { - DPRINTF(Fetch, "[tid:%i]: Setting to blocked\n",tid); + DPRINTF(Fetch, "[tid:%i] Setting to blocked\n",tid); fetchStatus[tid] = Blocked; @@ -1080,7 +1083,7 @@ DefaultFetch::checkSignalsAndUpdate(ThreadID tid) fetchStatus[tid] == Squashing) { // Switch status to running if fetch isn't being told to block or // squash this cycle. - DPRINTF(Fetch, "[tid:%i]: Done squashing, switching to running.\n", + DPRINTF(Fetch, "[tid:%i] Done squashing, switching to running.\n", tid); fetchStatus[tid] = Running; @@ -1111,11 +1114,11 @@ DefaultFetch::buildInst(ThreadID tid, StaticInstPtr staticInst, instruction->setThreadState(cpu->thread[tid]); - DPRINTF(Fetch, "[tid:%i]: Instruction PC %#x (%d) created " + DPRINTF(Fetch, "[tid:%i] Instruction PC %#x (%d) created " "[sn:%lli].\n", tid, thisPC.instAddr(), thisPC.microPC(), seq); - DPRINTF(Fetch, "[tid:%i]: Instruction is: %s\n", tid, + DPRINTF(Fetch, "[tid:%i] Instruction is: %s\n", tid, instruction->staticInst-> disassemble(thisPC.instAddr())); @@ -1137,7 +1140,7 @@ DefaultFetch::buildInst(ThreadID tid, StaticInstPtr staticInst, assert(numInst < fetchWidth); fetchQueue[tid].push_back(instruction); assert(fetchQueue[tid].size() <= fetchQueueSize); - DPRINTF(Fetch, "[tid:%i]: Fetch queue entry created (%i/%i).\n", + DPRINTF(Fetch, "[tid:%i] Fetch queue entry created (%i/%i).\n", tid, fetchQueue[tid].size(), fetchQueueSize); //toDecode->insts[toDecode->size++] = instruction; @@ -1183,7 +1186,7 @@ DefaultFetch::fetch(bool &status_change) // to running, otherwise do the cache access. Possibly move this up // to tick() function. if (fetchStatus[tid] == IcacheAccessComplete) { - DPRINTF(Fetch, "[tid:%i]: Icache miss is complete.\n", tid); + DPRINTF(Fetch, "[tid:%i] Icache miss is complete.\n", tid); fetchStatus[tid] = Running; status_change = true; @@ -1196,7 +1199,7 @@ DefaultFetch::fetch(bool &status_change) // from a macro-op, then start fetch from icache. if (!(fetchBufferValid[tid] && fetchBufferBlockPC == fetchBufferPC[tid]) && !inRom && !macroop[tid]) { - DPRINTF(Fetch, "[tid:%i]: Attempting to translate and read " + DPRINTF(Fetch, "[tid:%i] Attempting to translate and read " "instruction, starting at PC %s.\n", tid, thisPC); fetchCacheLine(fetchAddr, tid, thisPC.instAddr()); @@ -1213,13 +1216,13 @@ DefaultFetch::fetch(bool &status_change) // an delayed commit micro-op currently (delayed commit instructions // are not interruptable by interrupts, only faults) ++fetchMiscStallCycles; - DPRINTF(Fetch, "[tid:%i]: Fetch is stalled!\n", tid); + DPRINTF(Fetch, "[tid:%i] Fetch is stalled!\n", tid); return; } } else { if (fetchStatus[tid] == Idle) { ++fetchIdleCycles; - DPRINTF(Fetch, "[tid:%i]: Fetch is idle!\n", tid); + DPRINTF(Fetch, "[tid:%i] Fetch is idle!\n", tid); } // Status is Idle, so fetch should do nothing. @@ -1237,7 +1240,7 @@ DefaultFetch::fetch(bool &status_change) // instructions from the rest of the cache line and put them into the // queue heading to decode. - DPRINTF(Fetch, "[tid:%i]: Adding instructions to queue to " + DPRINTF(Fetch, "[tid:%i] Adding instructions to queue to " "decode.\n", tid); // Need to keep track of whether or not a predicted branch @@ -1379,13 +1382,13 @@ DefaultFetch::fetch(bool &status_change) } if (predictedBranch) { - DPRINTF(Fetch, "[tid:%i]: Done fetching, predicted branch " + DPRINTF(Fetch, "[tid:%i] Done fetching, predicted branch " "instruction encountered.\n", tid); } else if (numInst >= fetchWidth) { - DPRINTF(Fetch, "[tid:%i]: Done fetching, reached fetch bandwidth " + DPRINTF(Fetch, "[tid:%i] Done fetching, reached fetch bandwidth " "for this cycle.\n", tid); } else if (blkOffset >= fetchBufferSize) { - DPRINTF(Fetch, "[tid:%i]: Done fetching, reached the end of the" + DPRINTF(Fetch, "[tid:%i] Done fetching, reached the end of the" "fetch buffer.\n", tid); } @@ -1617,7 +1620,7 @@ DefaultFetch::pipelineIcacheAccesses(ThreadID tid) // Unless buffer already got the block, fetch it from icache. if (!(fetchBufferValid[tid] && fetchBufferBlockPC == fetchBufferPC[tid])) { - DPRINTF(Fetch, "[tid:%i]: Issuing a pipelined I-cache access, " + DPRINTF(Fetch, "[tid:%i] Issuing a pipelined I-cache access, " "starting at PC %s.\n", tid, thisPC); fetchCacheLine(fetchAddr, tid, thisPC.instAddr()); @@ -1639,36 +1642,37 @@ DefaultFetch::profileStall(ThreadID tid) { DPRINTF(Fetch, "Fetch has no active thread!\n"); } else if (fetchStatus[tid] == Blocked) { ++fetchBlockedCycles; - DPRINTF(Fetch, "[tid:%i]: Fetch is blocked!\n", tid); + DPRINTF(Fetch, "[tid:%i] Fetch is blocked!\n", tid); } else if (fetchStatus[tid] == Squashing) { ++fetchSquashCycles; - DPRINTF(Fetch, "[tid:%i]: Fetch is squashing!\n", tid); + DPRINTF(Fetch, "[tid:%i] Fetch is squashing!\n", tid); } else if (fetchStatus[tid] == IcacheWaitResponse) { ++icacheStallCycles; - DPRINTF(Fetch, "[tid:%i]: Fetch is waiting cache response!\n", + DPRINTF(Fetch, "[tid:%i] Fetch is waiting cache response!\n", tid); } else if (fetchStatus[tid] == ItlbWait) { ++fetchTlbCycles; - DPRINTF(Fetch, "[tid:%i]: Fetch is waiting ITLB walk to " + DPRINTF(Fetch, "[tid:%i] Fetch is waiting ITLB walk to " "finish!\n", tid); } else if (fetchStatus[tid] == TrapPending) { ++fetchPendingTrapStallCycles; - DPRINTF(Fetch, "[tid:%i]: Fetch is waiting for a pending trap!\n", + DPRINTF(Fetch, "[tid:%i] Fetch is waiting for a pending trap!\n", tid); } else if (fetchStatus[tid] == QuiescePending) { ++fetchPendingQuiesceStallCycles; - DPRINTF(Fetch, "[tid:%i]: Fetch is waiting for a pending quiesce " + DPRINTF(Fetch, "[tid:%i] Fetch is waiting for a pending quiesce " "instruction!\n", tid); } else if (fetchStatus[tid] == IcacheWaitRetry) { ++fetchIcacheWaitRetryStallCycles; - DPRINTF(Fetch, "[tid:%i]: Fetch is waiting for an I-cache retry!\n", + DPRINTF(Fetch, "[tid:%i] Fetch is waiting for an I-cache retry!\n", tid); } else if (fetchStatus[tid] == NoGoodAddr) { - DPRINTF(Fetch, "[tid:%i]: Fetch predicted non-executable address\n", + DPRINTF(Fetch, "[tid:%i] Fetch predicted non-executable address\n", tid); } else { - DPRINTF(Fetch, "[tid:%i]: Unexpected fetch stall reason (Status: %i).\n", - tid, fetchStatus[tid]); + DPRINTF(Fetch, "[tid:%i] Unexpected fetch stall reason " + "(Status: %i)\n", + tid, fetchStatus[tid]); } } diff --git a/src/cpu/o3/iew_impl.hh b/src/cpu/o3/iew_impl.hh index 6434ec8c3..56c182564 100644 --- a/src/cpu/o3/iew_impl.hh +++ b/src/cpu/o3/iew_impl.hh @@ -462,7 +462,7 @@ template void DefaultIEW::squash(ThreadID tid) { - DPRINTF(IEW, "[tid:%i]: Squashing all instructions.\n", tid); + DPRINTF(IEW, "[tid:%i] Squashing all instructions.\n", tid); // Tell the IQ to start squashing. instQueue.squash(tid); @@ -472,8 +472,10 @@ DefaultIEW::squash(ThreadID tid) updatedQueues = true; // Clear the skid buffer in case it has any data in it. - DPRINTF(IEW, "[tid:%i]: Removing skidbuffer instructions until [sn:%i].\n", - tid, fromCommit->commitInfo[tid].doneSeqNum); + DPRINTF(IEW, + "Removing skidbuffer instructions until " + "[sn:%llu] [tid:%i]\n", + fromCommit->commitInfo[tid].doneSeqNum, tid); while (!skidBuffer[tid].empty()) { if (skidBuffer[tid].front()->isLoad()) { @@ -496,8 +498,9 @@ template void DefaultIEW::squashDueToBranch(const DynInstPtr& inst, ThreadID tid) { - DPRINTF(IEW, "[tid:%i]: Squashing from a specific instruction, PC: %s " - "[sn:%i].\n", tid, inst->pcState(), inst->seqNum); + DPRINTF(IEW, "[tid:%i] [sn:%llu] Squashing from a specific instruction," + " PC: %s " + "\n", tid, inst->seqNum, inst->pcState() ); if (!toCommit->squash[tid] || inst->seqNum < toCommit->squashedSeqNum[tid]) { @@ -521,8 +524,8 @@ template void DefaultIEW::squashDueToMemOrder(const DynInstPtr& inst, ThreadID tid) { - DPRINTF(IEW, "[tid:%i]: Memory violation, squashing violator and younger " - "insts, PC: %s [sn:%i].\n", tid, inst->pcState(), inst->seqNum); + DPRINTF(IEW, "[tid:%i] Memory violation, squashing violator and younger " + "insts, PC: %s [sn:%llu].\n", tid, inst->pcState(), inst->seqNum); // Need to include inst->seqNum in the following comparison to cover the // corner case when a branch misprediction and a memory violation for the // same instruction (e.g. load PC) are detected in the same cycle. In this @@ -548,7 +551,7 @@ template void DefaultIEW::block(ThreadID tid) { - DPRINTF(IEW, "[tid:%u]: Blocking.\n", tid); + DPRINTF(IEW, "[tid:%i] Blocking.\n", tid); if (dispatchStatus[tid] != Blocked && dispatchStatus[tid] != Unblocking) { @@ -567,7 +570,7 @@ template void DefaultIEW::unblock(ThreadID tid) { - DPRINTF(IEW, "[tid:%i]: Reading instructions out of the skid " + DPRINTF(IEW, "[tid:%i] Reading instructions out of the skid " "buffer %u.\n",tid, tid); // If the skid bufffer is empty, signal back to previous stages to unblock. @@ -575,7 +578,7 @@ DefaultIEW::unblock(ThreadID tid) if (skidBuffer[tid].empty()) { toRename->iewUnblock[tid] = true; wroteToTimeBuffer = true; - DPRINTF(IEW, "[tid:%i]: Done unblocking.\n",tid); + DPRINTF(IEW, "[tid:%i] Done unblocking.\n",tid); dispatchStatus[tid] = Running; } } @@ -669,7 +672,7 @@ DefaultIEW::skidInsert(ThreadID tid) insts[tid].pop(); - DPRINTF(IEW,"[tid:%i]: Inserting [sn:%lli] PC:%s into " + DPRINTF(IEW,"[tid:%i] Inserting [sn:%lli] PC:%s into " "dispatch skidBuffer %i\n",tid, inst->seqNum, inst->pcState(),tid); @@ -764,10 +767,10 @@ DefaultIEW::checkStall(ThreadID tid) bool ret_val(false); if (fromCommit->commitInfo[tid].robSquashing) { - DPRINTF(IEW,"[tid:%i]: Stall from Commit stage detected.\n",tid); + DPRINTF(IEW,"[tid:%i] Stall from Commit stage detected.\n",tid); ret_val = true; } else if (instQueue.isFull(tid)) { - DPRINTF(IEW,"[tid:%i]: Stall: IQ is full.\n",tid); + DPRINTF(IEW,"[tid:%i] Stall: IQ is full.\n",tid); ret_val = true; } @@ -800,7 +803,7 @@ DefaultIEW::checkSignalsAndUpdate(ThreadID tid) } if (fromCommit->commitInfo[tid].robSquashing) { - DPRINTF(IEW, "[tid:%i]: ROB is still squashing.\n", tid); + DPRINTF(IEW, "[tid:%i] ROB is still squashing.\n", tid); dispatchStatus[tid] = Squashing; emptyRenameInsts(tid); @@ -816,7 +819,7 @@ DefaultIEW::checkSignalsAndUpdate(ThreadID tid) if (dispatchStatus[tid] == Blocked) { // Status from previous cycle was blocked, but there are no more stall // conditions. Switch over to unblocking. - DPRINTF(IEW, "[tid:%i]: Done blocking, switching to unblocking.\n", + DPRINTF(IEW, "[tid:%i] Done blocking, switching to unblocking.\n", tid); dispatchStatus[tid] = Unblocking; @@ -829,7 +832,7 @@ DefaultIEW::checkSignalsAndUpdate(ThreadID tid) if (dispatchStatus[tid] == Squashing) { // Switch status to running if rename isn't being told to block or // squash this cycle. - DPRINTF(IEW, "[tid:%i]: Done squashing, switching to running.\n", + DPRINTF(IEW, "[tid:%i] Done squashing, switching to running.\n", tid); dispatchStatus[tid] = Running; @@ -856,7 +859,7 @@ template void DefaultIEW::emptyRenameInsts(ThreadID tid) { - DPRINTF(IEW, "[tid:%i]: Removing incoming rename instructions\n", tid); + DPRINTF(IEW, "[tid:%i] Removing incoming rename instructions\n", tid); while (!insts[tid].empty()) { @@ -978,14 +981,14 @@ DefaultIEW::dispatchInsts(ThreadID tid) inst = insts_to_dispatch.front(); if (dispatchStatus[tid] == Unblocking) { - DPRINTF(IEW, "[tid:%i]: Issue: Examining instruction from skid " + DPRINTF(IEW, "[tid:%i] Issue: Examining instruction from skid " "buffer\n", tid); } // Make sure there's a valid instruction there. assert(inst); - DPRINTF(IEW, "[tid:%i]: Issue: Adding PC %s [sn:%lli] [tid:%i] to " + DPRINTF(IEW, "[tid:%i] Issue: Adding PC %s [sn:%lli] [tid:%i] to " "IQ.\n", tid, inst->pcState(), inst->seqNum, inst->threadNumber); @@ -995,7 +998,7 @@ DefaultIEW::dispatchInsts(ThreadID tid) // Check for squashed instructions. if (inst->isSquashed()) { - DPRINTF(IEW, "[tid:%i]: Issue: Squashed instruction encountered, " + DPRINTF(IEW, "[tid:%i] Issue: Squashed instruction encountered, " "not adding to IQ.\n", tid); ++iewDispSquashedInsts; @@ -1017,7 +1020,7 @@ DefaultIEW::dispatchInsts(ThreadID tid) // Check for full conditions. if (instQueue.isFull(tid)) { - DPRINTF(IEW, "[tid:%i]: Issue: IQ has become full.\n", tid); + DPRINTF(IEW, "[tid:%i] Issue: IQ has become full.\n", tid); // Call function to start blocking. block(tid); @@ -1035,7 +1038,7 @@ DefaultIEW::dispatchInsts(ThreadID tid) if ((inst->isAtomic() && ldstQueue.sqFull(tid)) || (inst->isLoad() && ldstQueue.lqFull(tid)) || (inst->isStore() && ldstQueue.sqFull(tid))) { - DPRINTF(IEW, "[tid:%i]: Issue: %s has become full.\n",tid, + DPRINTF(IEW, "[tid:%i] Issue: %s has become full.\n",tid, inst->isLoad() ? "LQ" : "SQ"); // Call function to start blocking. @@ -1052,7 +1055,7 @@ DefaultIEW::dispatchInsts(ThreadID tid) // Otherwise issue the instruction just fine. if (inst->isAtomic()) { - DPRINTF(IEW, "[tid:%i]: Issue: Memory instruction " + DPRINTF(IEW, "[tid:%i] Issue: Memory instruction " "encountered, adding to LSQ.\n", tid); ldstQueue.insertStore(inst); @@ -1070,7 +1073,7 @@ DefaultIEW::dispatchInsts(ThreadID tid) toRename->iewInfo[tid].dispatchedToSQ++; } else if (inst->isLoad()) { - DPRINTF(IEW, "[tid:%i]: Issue: Memory instruction " + DPRINTF(IEW, "[tid:%i] Issue: Memory instruction " "encountered, adding to LSQ.\n", tid); // Reserve a spot in the load store queue for this @@ -1083,7 +1086,7 @@ DefaultIEW::dispatchInsts(ThreadID tid) toRename->iewInfo[tid].dispatchedToLQ++; } else if (inst->isStore()) { - DPRINTF(IEW, "[tid:%i]: Issue: Memory instruction " + DPRINTF(IEW, "[tid:%i] Issue: Memory instruction " "encountered, adding to LSQ.\n", tid); ldstQueue.insertStore(inst); @@ -1111,7 +1114,7 @@ DefaultIEW::dispatchInsts(ThreadID tid) instQueue.insertBarrier(inst); add_to_iq = false; } else if (inst->isNop()) { - DPRINTF(IEW, "[tid:%i]: Issue: Nop instruction encountered, " + DPRINTF(IEW, "[tid:%i] Issue: Nop instruction encountered, " "skipping.\n", tid); inst->setIssued(); @@ -1129,7 +1132,7 @@ DefaultIEW::dispatchInsts(ThreadID tid) } if (add_to_iq && inst->isNonSpeculative()) { - DPRINTF(IEW, "[tid:%i]: Issue: Nonspeculative instruction " + DPRINTF(IEW, "[tid:%i] Issue: Nonspeculative instruction " "encountered, skipping.\n", tid); // Same as non-speculative stores. @@ -1162,7 +1165,7 @@ DefaultIEW::dispatchInsts(ThreadID tid) } if (!insts_to_dispatch.empty()) { - DPRINTF(IEW,"[tid:%i]: Issue: Bandwidth Full. Blocking.\n", tid); + DPRINTF(IEW,"[tid:%i] Issue: Bandwidth Full. Blocking.\n", tid); block(tid); toRename->iewUnblock[tid] = false; } @@ -1228,7 +1231,7 @@ DefaultIEW::executeInsts() DynInstPtr inst = instQueue.getInstToExecute(); - DPRINTF(IEW, "Execute: Processing PC %s, [tid:%i] [sn:%i].\n", + DPRINTF(IEW, "Execute: Processing PC %s, [tid:%i] [sn:%llu].\n", inst->pcState(), inst->threadNumber,inst->seqNum); // Notify potential listeners that this instruction has started @@ -1238,7 +1241,7 @@ DefaultIEW::executeInsts() // Check if the instruction is squashed; if so then skip it if (inst->isSquashed()) { DPRINTF(IEW, "Execute: Instruction was squashed. PC: %s, [tid:%i]" - " [sn:%i]\n", inst->pcState(), inst->threadNumber, + " [sn:%llu]\n", inst->pcState(), inst->threadNumber, inst->seqNum); // Consider this instruction executed so that commit can go @@ -1366,11 +1369,15 @@ DefaultIEW::executeInsts() if (inst->mispredicted() && !loadNotExecuted) { fetchRedirect[tid] = true; - DPRINTF(IEW, "Execute: Branch mispredict detected.\n"); - DPRINTF(IEW, "Predicted target was PC: %s.\n", - inst->readPredTarg()); - DPRINTF(IEW, "Execute: Redirecting fetch to PC: %s.\n", - inst->pcState()); + DPRINTF(IEW, "[tid:%i] [sn:%llu] Execute: " + "Branch mispredict detected.\n", + tid,inst->seqNum); + DPRINTF(IEW, "[tid:%i] [sn:%llu] " + "Predicted target was PC: %s\n", + tid,inst->seqNum,inst->readPredTarg()); + DPRINTF(IEW, "[tid:%i] [sn:%llu] Execute: " + "Redirecting fetch to PC: %s\n", + tid,inst->seqNum,inst->pcState()); // If incorrect, then signal the ROB that it must be squashed. squashDueToBranch(inst, tid); @@ -1664,11 +1671,18 @@ DefaultIEW::checkMisprediction(const DynInstPtr& inst) if (inst->mispredicted()) { fetchRedirect[tid] = true; - DPRINTF(IEW, "Execute: Branch mispredict detected.\n"); - DPRINTF(IEW, "Predicted target was PC:%#x, NPC:%#x.\n", + DPRINTF(IEW, "[tid:%i] [sn:%llu] Execute: " + "Branch mispredict detected.\n", + tid,inst->seqNum); + DPRINTF(IEW, "[tid:%i] [sn:%llu] Predicted target " + "was PC:%#x, NPC:%#x\n", + tid,inst->seqNum, inst->predInstAddr(), inst->predNextInstAddr()); - DPRINTF(IEW, "Execute: Redirecting fetch to PC: %#x," - " NPC: %#x.\n", inst->nextInstAddr(), + DPRINTF(IEW, "[tid:%i] [sn:%llu] Execute: " + "Redirecting fetch to PC: %#x, " + "NPC: %#x.\n", + tid,inst->seqNum, + inst->nextInstAddr(), inst->nextInstAddr()); // If incorrect, then signal the ROB that it must be squashed. squashDueToBranch(inst, tid); diff --git a/src/cpu/o3/inst_queue_impl.hh b/src/cpu/o3/inst_queue_impl.hh index aa12297d6..4a5262fd6 100644 --- a/src/cpu/o3/inst_queue_impl.hh +++ b/src/cpu/o3/inst_queue_impl.hh @@ -589,7 +589,7 @@ InstructionQueue::insert(const DynInstPtr &new_inst) // Make sure the instruction is valid assert(new_inst); - DPRINTF(IQ, "Adding instruction [sn:%lli] PC %s to the IQ.\n", + DPRINTF(IQ, "Adding instruction [sn:%llu] PC %s to the IQ.\n", new_inst->seqNum, new_inst->pcState()); assert(freeEntries != 0); @@ -639,7 +639,7 @@ InstructionQueue::insertNonSpec(const DynInstPtr &new_inst) nonSpecInsts[new_inst->seqNum] = new_inst; - DPRINTF(IQ, "Adding non-speculative instruction [sn:%lli] PC %s " + DPRINTF(IQ, "Adding non-speculative instruction [sn:%llu] PC %s " "to the IQ.\n", new_inst->seqNum, new_inst->pcState()); @@ -751,7 +751,7 @@ template void InstructionQueue::processFUCompletion(const DynInstPtr &inst, int fu_idx) { - DPRINTF(IQ, "Processing FU completion [sn:%lli]\n", inst->seqNum); + DPRINTF(IQ, "Processing FU completion [sn:%llu]\n", inst->seqNum); assert(!cpu->switchedOut()); // The CPU could have been sleeping until this op completed (*extremely* // long latency op). Wake it if it was. This may be overkill. @@ -886,7 +886,7 @@ InstructionQueue::scheduleReadyInsts() } DPRINTF(IQ, "Thread %i: Issuing instruction PC %s " - "[sn:%lli]\n", + "[sn:%llu]\n", tid, issuing_inst->pcState(), issuing_inst->seqNum); @@ -943,7 +943,7 @@ template void InstructionQueue::scheduleNonSpec(const InstSeqNum &inst) { - DPRINTF(IQ, "Marking nonspeculative instruction [sn:%lli] as ready " + DPRINTF(IQ, "Marking nonspeculative instruction [sn:%llu] as ready " "to execute.\n", inst); NonSpecMapIt inst_it = nonSpecInsts.find(inst); @@ -971,7 +971,7 @@ template void InstructionQueue::commit(const InstSeqNum &inst, ThreadID tid) { - DPRINTF(IQ, "[tid:%i]: Committing instructions older than [sn:%i]\n", + DPRINTF(IQ, "[tid:%i] Committing instructions older than [sn:%llu]\n", tid,inst); ListIt iq_it = instList[tid].begin(); @@ -1042,7 +1042,7 @@ InstructionQueue::wakeDependents(const DynInstPtr &completed_inst) DynInstPtr dep_inst = dependGraph.pop(dest_reg->flatIndex()); while (dep_inst) { - DPRINTF(IQ, "Waking up a dependent instruction, [sn:%lli] " + DPRINTF(IQ, "Waking up a dependent instruction, [sn:%llu] " "PC %s.\n", dep_inst->seqNum, dep_inst->pcState()); // Might want to give more information to the instruction @@ -1088,7 +1088,7 @@ InstructionQueue::addReadyMemInst(const DynInstPtr &ready_inst) } DPRINTF(IQ, "Instruction is ready to issue, putting it onto " - "the ready list, PC %s opclass:%i [sn:%lli].\n", + "the ready list, PC %s opclass:%i [sn:%llu].\n", ready_inst->pcState(), op_class, ready_inst->seqNum); } @@ -1096,7 +1096,7 @@ template void InstructionQueue::rescheduleMemInst(const DynInstPtr &resched_inst) { - DPRINTF(IQ, "Rescheduling mem inst [sn:%lli]\n", resched_inst->seqNum); + DPRINTF(IQ, "Rescheduling mem inst [sn:%llu]\n", resched_inst->seqNum); // Reset DTB translation state resched_inst->translationStarted(false); @@ -1119,7 +1119,7 @@ InstructionQueue::completeMemInst(const DynInstPtr &completed_inst) { ThreadID tid = completed_inst->threadNumber; - DPRINTF(IQ, "Completing mem instruction PC: %s [sn:%lli]\n", + DPRINTF(IQ, "Completing mem instruction PC: %s [sn:%llu]\n", completed_inst->pcState(), completed_inst->seqNum); ++freeEntries; @@ -1196,7 +1196,7 @@ template void InstructionQueue::squash(ThreadID tid) { - DPRINTF(IQ, "[tid:%i]: Starting to squash instructions in " + DPRINTF(IQ, "[tid:%i] Starting to squash instructions in " "the IQ.\n", tid); // Read instruction sequence number of last instruction out of the @@ -1217,7 +1217,7 @@ InstructionQueue::doSquash(ThreadID tid) ListIt squash_it = instList[tid].end(); --squash_it; - DPRINTF(IQ, "[tid:%i]: Squashing until sequence number %i!\n", + DPRINTF(IQ, "[tid:%i] Squashing until sequence number %i!\n", tid, squashedSeqNum[tid]); // Squash any instructions younger than the squashed sequence number @@ -1246,7 +1246,7 @@ InstructionQueue::doSquash(ThreadID tid) (squashed_inst->isMemRef() && !squashed_inst->memOpDone())) { - DPRINTF(IQ, "[tid:%i]: Instruction [sn:%lli] PC %s squashed.\n", + DPRINTF(IQ, "[tid:%i] Instruction [sn:%llu] PC %s squashed.\n", tid, squashed_inst->seqNum, squashed_inst->pcState()); bool is_acq_rel = squashed_inst->isMemBarrier() && @@ -1460,7 +1460,7 @@ InstructionQueue::addIfReady(const DynInstPtr &inst) OpClass op_class = inst->opClass(); DPRINTF(IQ, "Instruction is ready to issue, putting it onto " - "the ready list, PC %s opclass:%i [sn:%lli].\n", + "the ready list, PC %s opclass:%i [sn:%llu].\n", inst->pcState(), op_class, inst->seqNum); readyInsts[op_class].push(inst); @@ -1531,7 +1531,7 @@ InstructionQueue::dumpLists() cprintf("Non speculative list: "); while (non_spec_it != non_spec_end_it) { - cprintf("%s [sn:%lli]", (*non_spec_it).second->pcState(), + cprintf("%s [sn:%llu]", (*non_spec_it).second->pcState(), (*non_spec_it).second->seqNum); ++non_spec_it; } @@ -1545,7 +1545,7 @@ InstructionQueue::dumpLists() cprintf("List order: "); while (list_order_it != list_order_end_it) { - cprintf("%i OpClass:%i [sn:%lli] ", i, (*list_order_it).queueType, + cprintf("%i OpClass:%i [sn:%llu] ", i, (*list_order_it).queueType, (*list_order_it).oldestInst); ++list_order_it; @@ -1580,7 +1580,7 @@ InstructionQueue::dumpInsts() } } - cprintf("PC: %s\n[sn:%lli]\n[tid:%i]\n" + cprintf("PC: %s\n[sn:%llu]\n[tid:%i]\n" "Issued:%i\nSquashed:%i\n", (*inst_list_it)->pcState(), (*inst_list_it)->seqNum, @@ -1622,7 +1622,7 @@ InstructionQueue::dumpInsts() } } - cprintf("PC: %s\n[sn:%lli]\n[tid:%i]\n" + cprintf("PC: %s\n[sn:%llu]\n[tid:%i]\n" "Issued:%i\nSquashed:%i\n", (*inst_list_it)->pcState(), (*inst_list_it)->seqNum, diff --git a/src/cpu/o3/lsq_unit.hh b/src/cpu/o3/lsq_unit.hh index 3be67bec4..5c64971c1 100644 --- a/src/cpu/o3/lsq_unit.hh +++ b/src/cpu/o3/lsq_unit.hh @@ -852,7 +852,7 @@ LSQUnit::write(LSQRequest *req, uint8_t *data, int store_idx) assert(storeQueue[store_idx].valid()); DPRINTF(LSQUnit, "Doing write to store idx %i, addr %#x | storeHead:%i " - "[sn:%i]\n", + "[sn:%llu]\n", store_idx - 1, req->request()->getPaddr(), storeQueue.head() - 1, storeQueue[store_idx].instruction()->seqNum); diff --git a/src/cpu/o3/lsq_unit_impl.hh b/src/cpu/o3/lsq_unit_impl.hh index adb24cbc5..62402bf4f 100644 --- a/src/cpu/o3/lsq_unit_impl.hh +++ b/src/cpu/o3/lsq_unit_impl.hh @@ -1091,7 +1091,7 @@ LSQUnit::dumpInsts() const for (const auto& e: loadQueue) { const DynInstPtr &inst(e.instruction()); - cprintf("%s.[sn:%i] ", inst->pcState(), inst->seqNum); + cprintf("%s.[sn:%llu] ", inst->pcState(), inst->seqNum); } cprintf("\n"); @@ -1100,7 +1100,7 @@ LSQUnit::dumpInsts() const for (const auto& e: storeQueue) { const DynInstPtr &inst(e.instruction()); - cprintf("%s.[sn:%i] ", inst->pcState(), inst->seqNum); + cprintf("%s.[sn:%llu] ", inst->pcState(), inst->seqNum); } cprintf("\n"); diff --git a/src/cpu/o3/mem_dep_unit_impl.hh b/src/cpu/o3/mem_dep_unit_impl.hh index f1d0e2313..7d8c357b0 100644 --- a/src/cpu/o3/mem_dep_unit_impl.hh +++ b/src/cpu/o3/mem_dep_unit_impl.hh @@ -593,7 +593,7 @@ MemDepUnit::dumpLists() int num = 0; while (inst_list_it != instList[tid].end()) { - cprintf("Instruction:%i\nPC: %s\n[sn:%i]\n[tid:%i]\nIssued:%i\n" + cprintf("Instruction:%i\nPC: %s\n[sn:%llu]\n[tid:%i]\nIssued:%i\n" "Squashed:%i\n\n", num, (*inst_list_it)->pcState(), (*inst_list_it)->seqNum, diff --git a/src/cpu/o3/rename_impl.hh b/src/cpu/o3/rename_impl.hh index c24a09711..43f0b2746 100644 --- a/src/cpu/o3/rename_impl.hh +++ b/src/cpu/o3/rename_impl.hh @@ -374,7 +374,8 @@ template void DefaultRename::squash(const InstSeqNum &squash_seq_num, ThreadID tid) { - DPRINTF(Rename, "[tid:%u]: Squashing instructions.\n",tid); + DPRINTF(Rename, "[tid:%i] [squash sn:%llu] Squashing instructions.\n", + tid,squash_seq_num); // Clear the stall signal if rename was blocked or unblocking before. // If it still needs to block, the blocking should happen the next @@ -387,7 +388,9 @@ DefaultRename::squash(const InstSeqNum &squash_seq_num, ThreadID tid) serializeInst[tid] = NULL; } else if (renameStatus[tid] == SerializeStall) { if (serializeInst[tid]->seqNum <= squash_seq_num) { - DPRINTF(Rename, "Rename will resume serializing after squash\n"); + DPRINTF(Rename, "[tid:%i] [squash sn:%llu] " + "Rename will resume serializing after squash\n", + tid,squash_seq_num); resumeSerialize = true; assert(serializeInst[tid]); } else { @@ -520,8 +523,10 @@ DefaultRename::rename(bool &status_change, ThreadID tid) if (renameStatus[tid] == Running || renameStatus[tid] == Idle) { - DPRINTF(Rename, "[tid:%u]: Not blocked, so attempting to run " - "stage.\n", tid); + DPRINTF(Rename, + "[tid:%i] " + "Not blocked, so attempting to run stage.\n", + tid); renameInsts(tid); } else if (renameStatus[tid] == Unblocking) { @@ -551,7 +556,7 @@ DefaultRename::renameInsts(ThreadID tid) // Check the decode queue to see if instructions are available. // If there are no available instructions to rename, then do nothing. if (insts_available == 0) { - DPRINTF(Rename, "[tid:%u]: Nothing to do, breaking out early.\n", + DPRINTF(Rename, "[tid:%i] Nothing to do, breaking out early.\n", tid); // Should I change status to idle? ++renameIdleCycles; @@ -577,13 +582,11 @@ DefaultRename::renameInsts(ThreadID tid) // Check if there's any space left. if (min_free_entries <= 0) { - DPRINTF(Rename, "[tid:%u]: Blocking due to no free ROB/IQ/ " - "entries.\n" + DPRINTF(Rename, + "[tid:%i] Blocking due to no free ROB/IQ/ entries.\n" "ROB has %i free entries.\n" "IQ has %i free entries.\n", - tid, - free_rob_entries, - free_iq_entries); + tid, free_rob_entries, free_iq_entries); blockThisCycle = true; @@ -593,9 +596,11 @@ DefaultRename::renameInsts(ThreadID tid) return; } else if (min_free_entries < insts_available) { - DPRINTF(Rename, "[tid:%u]: Will have to block this cycle." - "%i insts available, but only %i insts can be " - "renamed due to ROB/IQ/LSQ limits.\n", + DPRINTF(Rename, + "[tid:%i] " + "Will have to block this cycle. " + "%i insts available, " + "but only %i insts can be renamed due to ROB/IQ/LSQ limits.\n", tid, insts_available, min_free_entries); insts_available = min_free_entries; @@ -608,11 +613,15 @@ DefaultRename::renameInsts(ThreadID tid) InstQueue &insts_to_rename = renameStatus[tid] == Unblocking ? skidBuffer[tid] : insts[tid]; - DPRINTF(Rename, "[tid:%u]: %i available instructions to " - "send iew.\n", tid, insts_available); + DPRINTF(Rename, + "[tid:%i] " + "%i available instructions to send iew.\n", + tid, insts_available); - DPRINTF(Rename, "[tid:%u]: %i insts pipelining from Rename | %i insts " - "dispatched to IQ last cycle.\n", + DPRINTF(Rename, + "[tid:%i] " + "%i insts pipelining from Rename | " + "%i insts dispatched to IQ last cycle.\n", tid, instsInProgress[tid], fromIEW->iewInfo[tid].dispatched); // Handle serializing the next instruction if necessary. @@ -628,7 +637,7 @@ DefaultRename::renameInsts(ThreadID tid) int renamed_insts = 0; while (insts_available > 0 && toIEWIndex < renameWidth) { - DPRINTF(Rename, "[tid:%u]: Sending instructions to IEW.\n", tid); + DPRINTF(Rename, "[tid:%i] Sending instructions to IEW.\n", tid); assert(!insts_to_rename.empty()); @@ -640,7 +649,7 @@ DefaultRename::renameInsts(ThreadID tid) if (inst->isLoad()) { if (calcFreeLQEntries(tid) <= 0) { - DPRINTF(Rename, "[tid:%u]: Cannot rename due to no free LQ\n"); + DPRINTF(Rename, "[tid:%i] Cannot rename due to no free LQ\n"); source = LQ; incrFullStat(source); break; @@ -649,7 +658,7 @@ DefaultRename::renameInsts(ThreadID tid) if (inst->isStore() || inst->isAtomic()) { if (calcFreeSQEntries(tid) <= 0) { - DPRINTF(Rename, "[tid:%u]: Cannot rename due to no free SQ\n"); + DPRINTF(Rename, "[tid:%i] Cannot rename due to no free SQ\n"); source = SQ; incrFullStat(source); break; @@ -659,14 +668,17 @@ DefaultRename::renameInsts(ThreadID tid) insts_to_rename.pop_front(); if (renameStatus[tid] == Unblocking) { - DPRINTF(Rename,"[tid:%u]: Removing [sn:%lli] PC:%s from rename " - "skidBuffer\n", tid, inst->seqNum, inst->pcState()); + DPRINTF(Rename, + "[tid:%i] " + "Removing [sn:%llu] PC:%s from rename skidBuffer\n", + tid, inst->seqNum, inst->pcState()); } if (inst->isSquashed()) { - DPRINTF(Rename, "[tid:%u]: instruction %i with PC %s is " - "squashed, skipping.\n", tid, inst->seqNum, - inst->pcState()); + DPRINTF(Rename, + "[tid:%i] " + "instruction %i with PC %s is squashed, skipping.\n", + tid, inst->seqNum, inst->pcState()); ++renameSquashedInsts; @@ -676,8 +688,10 @@ DefaultRename::renameInsts(ThreadID tid) continue; } - DPRINTF(Rename, "[tid:%u]: Processing instruction [sn:%lli] with " - "PC %s.\n", tid, inst->seqNum, inst->pcState()); + DPRINTF(Rename, + "[tid:%i] " + "Processing instruction [sn:%llu] with PC %s.\n", + tid, inst->seqNum, inst->pcState()); // Check here to make sure there are enough destination registers // to rename to. Otherwise block. @@ -687,8 +701,9 @@ DefaultRename::renameInsts(ThreadID tid) inst->numVecElemDestRegs(), inst->numVecPredDestRegs(), inst->numCCDestRegs())) { - DPRINTF(Rename, "Blocking due to lack of free " - "physical registers to rename to.\n"); + DPRINTF(Rename, + "Blocking due to " + " lack of free physical registers to rename to.\n"); blockThisCycle = true; insts_to_rename.push_front(inst); ++renameFullRegistersEvents; @@ -796,7 +811,7 @@ DefaultRename::skidInsert(ThreadID tid) assert(tid == inst->threadNumber); - DPRINTF(Rename, "[tid:%u]: Inserting [sn:%lli] PC: %s into Rename " + DPRINTF(Rename, "[tid:%i] Inserting [sn:%llu] PC: %s into Rename " "skidBuffer\n", tid, inst->seqNum, inst->pcState()); ++renameSkidInsts; @@ -810,7 +825,7 @@ DefaultRename::skidInsert(ThreadID tid) warn("Skidbuffer contents:\n"); for (it = skidBuffer[tid].begin(); it != skidBuffer[tid].end(); it++) { - warn("[tid:%u]: %s [sn:%i].\n", tid, + warn("[tid:%i] %s [sn:%llu].\n", tid, (*it)->staticInst->disassemble(inst->instAddr()), (*it)->seqNum); } @@ -894,7 +909,7 @@ template bool DefaultRename::block(ThreadID tid) { - DPRINTF(Rename, "[tid:%u]: Blocking.\n", tid); + DPRINTF(Rename, "[tid:%i] Blocking.\n", tid); // Add the current inputs onto the skid buffer, so they can be // reprocessed when this stage unblocks. @@ -928,12 +943,12 @@ template bool DefaultRename::unblock(ThreadID tid) { - DPRINTF(Rename, "[tid:%u]: Trying to unblock.\n", tid); + DPRINTF(Rename, "[tid:%i] Trying to unblock.\n", tid); // Rename is done unblocking if the skid buffer is empty. if (skidBuffer[tid].empty() && renameStatus[tid] != SerializeStall) { - DPRINTF(Rename, "[tid:%u]: Done unblocking.\n", tid); + DPRINTF(Rename, "[tid:%i] Done unblocking.\n", tid); toDecode->renameUnblock[tid] = true; wroteToTimeBuffer = true; @@ -960,7 +975,7 @@ DefaultRename::doSquash(const InstSeqNum &squashed_seq_num, ThreadID tid) hb_it->instSeqNum > squashed_seq_num) { assert(hb_it != historyBuffer[tid].end()); - DPRINTF(Rename, "[tid:%u]: Removing history entry with sequence " + DPRINTF(Rename, "[tid:%i] Removing history entry with sequence " "number %i.\n", tid, hb_it->instSeqNum); // Undo the rename mapping only if it was really a change. @@ -997,8 +1012,8 @@ template void DefaultRename::removeFromHistory(InstSeqNum inst_seq_num, ThreadID tid) { - DPRINTF(Rename, "[tid:%u]: Removing a committed instruction from the " - "history buffer %u (size=%i), until [sn:%lli].\n", + DPRINTF(Rename, "[tid:%i] Removing a committed instruction from the " + "history buffer %u (size=%i), until [sn:%llu].\n", tid, tid, historyBuffer[tid].size(), inst_seq_num); typename std::list::iterator hb_it = @@ -1007,11 +1022,13 @@ DefaultRename::removeFromHistory(InstSeqNum inst_seq_num, ThreadID tid) --hb_it; if (historyBuffer[tid].empty()) { - DPRINTF(Rename, "[tid:%u]: History buffer is empty.\n", tid); + DPRINTF(Rename, "[tid:%i] History buffer is empty.\n", tid); return; } else if (hb_it->instSeqNum > inst_seq_num) { - DPRINTF(Rename, "[tid:%u]: Old sequence number encountered. Ensure " - "that a syscall happened recently.\n", tid); + DPRINTF(Rename, "[tid:%i] [sn:%llu] " + "Old sequence number encountered. " + "Ensure that a syscall happened recently.\n", + tid,inst_seq_num); return; } @@ -1023,8 +1040,8 @@ DefaultRename::removeFromHistory(InstSeqNum inst_seq_num, ThreadID tid) hb_it != historyBuffer[tid].end() && hb_it->instSeqNum <= inst_seq_num) { - DPRINTF(Rename, "[tid:%u]: Freeing up older rename of reg %i (%s), " - "[sn:%lli].\n", + DPRINTF(Rename, "[tid:%i] Freeing up older rename of reg %i (%s), " + "[sn:%llu].\n", tid, hb_it->prevPhysReg->index(), hb_it->prevPhysReg->className(), hb_it->instSeqNum); @@ -1079,26 +1096,29 @@ DefaultRename::renameSrcRegs(const DynInstPtr &inst, ThreadID tid) panic("Invalid register class: %d.", src_reg.classValue()); } - DPRINTF(Rename, "[tid:%u]: Looking up %s arch reg %i" - ", got phys reg %i (%s)\n", tid, - src_reg.className(), src_reg.index(), - renamed_reg->index(), + DPRINTF(Rename, + "[tid:%i] " + "Looking up %s arch reg %i, got phys reg %i (%s)\n", + tid, src_reg.className(), + src_reg.index(), renamed_reg->index(), renamed_reg->className()); inst->renameSrcReg(src_idx, renamed_reg); // See if the register is ready or not. if (scoreboard->getReg(renamed_reg)) { - DPRINTF(Rename, "[tid:%u]: Register %d (flat: %d) (%s)" - " is ready.\n", tid, renamed_reg->index(), - renamed_reg->flatIndex(), + DPRINTF(Rename, + "[tid:%i] " + "Register %d (flat: %d) (%s) is ready.\n", + tid, renamed_reg->index(), renamed_reg->flatIndex(), renamed_reg->className()); inst->markSrcRegReady(src_idx); } else { - DPRINTF(Rename, "[tid:%u]: Register %d (flat: %d) (%s)" - " is not ready.\n", tid, renamed_reg->index(), - renamed_reg->flatIndex(), + DPRINTF(Rename, + "[tid:%i] " + "Register %d (flat: %d) (%s) is not ready.\n", + tid, renamed_reg->index(), renamed_reg->flatIndex(), renamed_reg->className()); } @@ -1128,9 +1148,10 @@ DefaultRename::renameDestRegs(const DynInstPtr &inst, ThreadID tid) // Mark Scoreboard entry as not ready scoreboard->unsetReg(rename_result.first); - DPRINTF(Rename, "[tid:%u]: Renaming arch reg %i (%s) to physical " - "reg %i (%i).\n", tid, dest_reg.index(), - dest_reg.className(), + DPRINTF(Rename, + "[tid:%i] " + "Renaming arch reg %i (%s) to physical reg %i (%i).\n", + tid, dest_reg.index(), dest_reg.className(), rename_result.first->index(), rename_result.first->flatIndex()); @@ -1141,10 +1162,10 @@ DefaultRename::renameDestRegs(const DynInstPtr &inst, ThreadID tid) historyBuffer[tid].push_front(hb_entry); - DPRINTF(Rename, "[tid:%u]: Adding instruction to history buffer " - "(size=%i), [sn:%lli].\n",tid, - historyBuffer[tid].size(), - (*historyBuffer[tid].begin()).instSeqNum); + DPRINTF(Rename, "[tid:%i] [sn:%llu] " + "Adding instruction to history buffer (size=%i).\n", + tid,(*historyBuffer[tid].begin()).instSeqNum, + historyBuffer[tid].size()); // Tell the instruction to rename the appropriate destination // register (dest_idx) to the new physical register @@ -1166,7 +1187,7 @@ DefaultRename::calcFreeROBEntries(ThreadID tid) int num_free = freeEntries[tid].robEntries - (instsInProgress[tid] - fromIEW->iewInfo[tid].dispatched); - //DPRINTF(Rename,"[tid:%i]: %i rob free\n",tid,num_free); + //DPRINTF(Rename,"[tid:%i] %i rob free\n",tid,num_free); return num_free; } @@ -1178,7 +1199,7 @@ DefaultRename::calcFreeIQEntries(ThreadID tid) int num_free = freeEntries[tid].iqEntries - (instsInProgress[tid] - fromIEW->iewInfo[tid].dispatched); - //DPRINTF(Rename,"[tid:%i]: %i iq free\n",tid,num_free); + //DPRINTF(Rename,"[tid:%i] %i iq free\n",tid,num_free); return num_free; } @@ -1189,9 +1210,11 @@ DefaultRename::calcFreeLQEntries(ThreadID tid) { int num_free = freeEntries[tid].lqEntries - (loadsInProgress[tid] - fromIEW->iewInfo[tid].dispatchedToLQ); - DPRINTF(Rename, "calcFreeLQEntries: free lqEntries: %d, loadsInProgress: %d, " - "loads dispatchedToLQ: %d\n", freeEntries[tid].lqEntries, - loadsInProgress[tid], fromIEW->iewInfo[tid].dispatchedToLQ); + DPRINTF(Rename, + "calcFreeLQEntries: free lqEntries: %d, loadsInProgress: %d, " + "loads dispatchedToLQ: %d\n", + freeEntries[tid].lqEntries, loadsInProgress[tid], + fromIEW->iewInfo[tid].dispatchedToLQ); return num_free; } @@ -1242,23 +1265,23 @@ DefaultRename::checkStall(ThreadID tid) bool ret_val = false; if (stalls[tid].iew) { - DPRINTF(Rename,"[tid:%i]: Stall from IEW stage detected.\n", tid); + DPRINTF(Rename,"[tid:%i] Stall from IEW stage detected.\n", tid); ret_val = true; } else if (calcFreeROBEntries(tid) <= 0) { - DPRINTF(Rename,"[tid:%i]: Stall: ROB has 0 free entries.\n", tid); + DPRINTF(Rename,"[tid:%i] Stall: ROB has 0 free entries.\n", tid); ret_val = true; } else if (calcFreeIQEntries(tid) <= 0) { - DPRINTF(Rename,"[tid:%i]: Stall: IQ has 0 free entries.\n", tid); + DPRINTF(Rename,"[tid:%i] Stall: IQ has 0 free entries.\n", tid); ret_val = true; } else if (calcFreeLQEntries(tid) <= 0 && calcFreeSQEntries(tid) <= 0) { - DPRINTF(Rename,"[tid:%i]: Stall: LSQ has 0 free entries.\n", tid); + DPRINTF(Rename,"[tid:%i] Stall: LSQ has 0 free entries.\n", tid); ret_val = true; } else if (renameMap[tid]->numFreeEntries() <= 0) { - DPRINTF(Rename,"[tid:%i]: Stall: RenameMap has 0 free entries.\n", tid); + DPRINTF(Rename,"[tid:%i] Stall: RenameMap has 0 free entries.\n", tid); ret_val = true; } else if (renameStatus[tid] == SerializeStall && (!emptyROB[tid] || instsInProgress[tid])) { - DPRINTF(Rename,"[tid:%i]: Stall: Serialize stall and ROB is not " + DPRINTF(Rename,"[tid:%i] Stall: Serialize stall and ROB is not " "empty.\n", tid); ret_val = true; @@ -1285,7 +1308,7 @@ DefaultRename::readFreeEntries(ThreadID tid) emptyROB[tid] = fromCommit->commitInfo[tid].emptyROB; } - DPRINTF(Rename, "[tid:%i]: Free IQ: %i, Free ROB: %i, " + DPRINTF(Rename, "[tid:%i] Free IQ: %i, Free ROB: %i, " "Free LQ: %i, Free SQ: %i, FreeRM %i(%i %i %i %i %i)\n", tid, freeEntries[tid].iqEntries, @@ -1299,7 +1322,7 @@ DefaultRename::readFreeEntries(ThreadID tid) renameMap[tid]->numFreePredEntries(), renameMap[tid]->numFreeCCEntries()); - DPRINTF(Rename, "[tid:%i]: %i instructions not yet in ROB\n", + DPRINTF(Rename, "[tid:%i] %i instructions not yet in ROB\n", tid, instsInProgress[tid]); } @@ -1321,7 +1344,7 @@ DefaultRename::checkSignalsAndUpdate(ThreadID tid) readStallSignals(tid); if (fromCommit->commitInfo[tid].squash) { - DPRINTF(Rename, "[tid:%u]: Squashing instructions due to squash from " + DPRINTF(Rename, "[tid:%i] Squashing instructions due to squash from " "commit.\n", tid); squash(fromCommit->commitInfo[tid].doneSeqNum, tid); @@ -1334,7 +1357,7 @@ DefaultRename::checkSignalsAndUpdate(ThreadID tid) } if (renameStatus[tid] == Blocked) { - DPRINTF(Rename, "[tid:%u]: Done blocking, switching to unblocking.\n", + DPRINTF(Rename, "[tid:%i] Done blocking, switching to unblocking.\n", tid); renameStatus[tid] = Unblocking; @@ -1348,20 +1371,20 @@ DefaultRename::checkSignalsAndUpdate(ThreadID tid) // Switch status to running if rename isn't being told to block or // squash this cycle. if (resumeSerialize) { - DPRINTF(Rename, "[tid:%u]: Done squashing, switching to serialize.\n", - tid); + DPRINTF(Rename, + "[tid:%i] Done squashing, switching to serialize.\n", tid); renameStatus[tid] = SerializeStall; return true; } else if (resumeUnblocking) { - DPRINTF(Rename, "[tid:%u]: Done squashing, switching to unblocking.\n", + DPRINTF(Rename, + "[tid:%i] Done squashing, switching to unblocking.\n", tid); renameStatus[tid] = Unblocking; return true; } else { - DPRINTF(Rename, "[tid:%u]: Done squashing, switching to running.\n", + DPRINTF(Rename, "[tid:%i] Done squashing, switching to running.\n", tid); - renameStatus[tid] = Running; return false; } @@ -1369,7 +1392,7 @@ DefaultRename::checkSignalsAndUpdate(ThreadID tid) if (renameStatus[tid] == SerializeStall) { // Stall ends once the ROB is free. - DPRINTF(Rename, "[tid:%u]: Done with serialize stall, switching to " + DPRINTF(Rename, "[tid:%i] Done with serialize stall, switching to " "unblocking.\n", tid); DynInstPtr serial_inst = serializeInst[tid]; @@ -1378,7 +1401,7 @@ DefaultRename::checkSignalsAndUpdate(ThreadID tid) unblock(tid); - DPRINTF(Rename, "[tid:%u]: Processing instruction [%lli] with " + DPRINTF(Rename, "[tid:%i] Processing instruction [%lli] with " "PC %s.\n", tid, serial_inst->seqNum, serial_inst->pcState()); // Put instruction into queue here. @@ -1390,7 +1413,7 @@ DefaultRename::checkSignalsAndUpdate(ThreadID tid) insts[tid].push_front(serial_inst); } - DPRINTF(Rename, "[tid:%u]: Instruction must be processed by rename." + DPRINTF(Rename, "[tid:%i] Instruction must be processed by rename." " Adding to front of list.\n", tid); serializeInst[tid] = NULL; diff --git a/src/cpu/o3/rob_impl.hh b/src/cpu/o3/rob_impl.hh index 2942c7ac5..5d5d821b8 100644 --- a/src/cpu/o3/rob_impl.hh +++ b/src/cpu/o3/rob_impl.hh @@ -254,8 +254,8 @@ ROB::retireHead(ThreadID tid) assert(head_inst->readyToCommit()); - DPRINTF(ROB, "[tid:%u]: Retiring head instruction, " - "instruction PC %s, [sn:%lli]\n", tid, head_inst->pcState(), + DPRINTF(ROB, "[tid:%i] Retiring head instruction, " + "instruction PC %s, [sn:%llu]\n", tid, head_inst->pcState(), head_inst->seqNum); --numInstsInROB; @@ -323,13 +323,13 @@ void ROB::doSquash(ThreadID tid) { robWrites++; - DPRINTF(ROB, "[tid:%u]: Squashing instructions until [sn:%i].\n", + DPRINTF(ROB, "[tid:%i] Squashing instructions until [sn:%llu].\n", tid, squashedSeqNum[tid]); assert(squashIt[tid] != instList[tid].end()); if ((*squashIt[tid])->seqNum < squashedSeqNum[tid]) { - DPRINTF(ROB, "[tid:%u]: Done squashing instructions.\n", + DPRINTF(ROB, "[tid:%i] Done squashing instructions.\n", tid); squashIt[tid] = instList[tid].end(); @@ -346,7 +346,7 @@ ROB::doSquash(ThreadID tid) (*squashIt[tid])->seqNum > squashedSeqNum[tid]; ++numSquashed) { - DPRINTF(ROB, "[tid:%u]: Squashing instruction PC %s, seq num %i.\n", + DPRINTF(ROB, "[tid:%i] Squashing instruction PC %s, seq num %i.\n", (*squashIt[tid])->threadNumber, (*squashIt[tid])->pcState(), (*squashIt[tid])->seqNum); @@ -381,7 +381,7 @@ ROB::doSquash(ThreadID tid) // Check if ROB is done squashing. if ((*squashIt[tid])->seqNum <= squashedSeqNum[tid]) { - DPRINTF(ROB, "[tid:%u]: Done squashing instructions.\n", + DPRINTF(ROB, "[tid:%i] Done squashing instructions.\n", tid); squashIt[tid] = instList[tid].end(); @@ -481,7 +481,7 @@ ROB::squash(InstSeqNum squash_num, ThreadID tid) { if (isEmpty(tid)) { DPRINTF(ROB, "Does not need to squash due to being empty " - "[sn:%i]\n", + "[sn:%llu]\n", squash_num); return; diff --git a/src/cpu/pred/bpred_unit.cc b/src/cpu/pred/bpred_unit.cc index 33604799d..176b6a73f 100644 --- a/src/cpu/pred/bpred_unit.cc +++ b/src/cpu/pred/bpred_unit.cc @@ -196,7 +196,9 @@ BPredUnit::predict(const StaticInstPtr &inst, const InstSeqNum &seqNum, void *indirect_history = NULL; if (inst->isUncondCtrl()) { - DPRINTF(Branch, "[tid:%i]: Unconditional control.\n", tid); + DPRINTF(Branch, "[tid:%i] [sn:%llu] " + "Unconditional control\n", + tid,seqNum); pred_taken = true; // Tell the BP there was an unconditional branch. uncondBranch(tid, pc.instAddr(), bp_history); @@ -204,8 +206,9 @@ BPredUnit::predict(const StaticInstPtr &inst, const InstSeqNum &seqNum, ++condPredicted; pred_taken = lookup(tid, pc.instAddr(), bp_history); - DPRINTF(Branch, "[tid:%i]: [sn:%i] Branch predictor" - " predicted %i for PC %s\n", tid, seqNum, pred_taken, pc); + DPRINTF(Branch, "[tid:%i] [sn:%llu] " + "Branch predictor predicted %i for PC %s\n", + tid, seqNum, pred_taken, pc); } const bool orig_pred_taken = pred_taken; @@ -213,7 +216,8 @@ BPredUnit::predict(const StaticInstPtr &inst, const InstSeqNum &seqNum, iPred.genIndirectInfo(tid, indirect_history); } - DPRINTF(Branch, "[tid:%i]: [sn:%i] Creating prediction history " + DPRINTF(Branch, "[tid:%i] [sn:%llu] " + "Creating prediction history " "for PC %s\n", tid, seqNum, pc); PredictorHistory predict_record(seqNum, pc.instAddr(), pred_taken, @@ -236,9 +240,9 @@ BPredUnit::predict(const StaticInstPtr &inst, const InstSeqNum &seqNum, RAS[tid].pop(); - DPRINTF(Branch, "[tid:%i]: Instruction %s is a return, " - "RAS predicted target: %s, RAS index: %i.\n", - tid, pc, target, predict_record.RASIndex); + DPRINTF(Branch, "[tid:%i] [sn:%llu] Instruction %s is a return, " + "RAS predicted target: %s, RAS index: %i\n", + tid, seqNum, pc, target, predict_record.RASIndex); } else { ++BTBLookups; @@ -250,33 +254,35 @@ BPredUnit::predict(const StaticInstPtr &inst, const InstSeqNum &seqNum, // be popped off if the speculation is incorrect. predict_record.wasCall = true; - DPRINTF(Branch, "[tid:%i]: Instruction %s was a " - "call, adding %s to the RAS index: %i.\n", - tid, pc, pc, RAS[tid].topIdx()); + DPRINTF(Branch, + "[tid:%i] [sn:%llu] Instruction %s was a call, adding " + "%s to the RAS index: %i\n", + tid, seqNum, pc, pc, RAS[tid].topIdx()); } if (inst->isDirectCtrl() || !useIndirect) { // Check BTB on direct branches if (BTB.valid(pc.instAddr(), tid)) { ++BTBHits; - // If it's not a return, use the BTB to get target addr. target = BTB.lookup(pc.instAddr(), tid); - - DPRINTF(Branch, "[tid:%i]: Instruction %s predicted" - " target is %s.\n", tid, pc, target); - + DPRINTF(Branch, + "[tid:%i] [sn:%llu] Instruction %s predicted " + "target is %s\n", + tid, seqNum, pc, target); } else { - DPRINTF(Branch, "[tid:%i]: BTB doesn't have a " - "valid entry.\n",tid); + DPRINTF(Branch, "[tid:%i] [sn:%llu] BTB doesn't have a " + "valid entry\n",tid,seqNum); pred_taken = false; // The Direction of the branch predictor is altered // because the BTB did not have an entry // The predictor needs to be updated accordingly if (!inst->isCall() && !inst->isReturn()) { btbUpdate(tid, pc.instAddr(), bp_history); - DPRINTF(Branch, "[tid:%i]:[sn:%i] btbUpdate" - " called for %s\n", tid, seqNum, pc); + DPRINTF(Branch, + "[tid:%i] [sn:%llu] btbUpdate " + "called for %s\n", + tid, seqNum, pc); } else if (inst->isCall() && !inst->isUncondCtrl()) { RAS[tid].pop(); predict_record.pushedRAS = false; @@ -290,13 +296,19 @@ BPredUnit::predict(const StaticInstPtr &inst, const InstSeqNum &seqNum, if (iPred.lookup(pc.instAddr(), target, tid)) { // Indirect predictor hit ++indirectHits; - DPRINTF(Branch, "[tid:%i]: Instruction %s predicted " - "indirect target is %s.\n", tid, pc, target); + DPRINTF(Branch, + "[tid:%i] [sn:%llu] " + "Instruction %s predicted " + "indirect target is %s\n", + tid, seqNum, pc, target); } else { ++indirectMisses; pred_taken = false; - DPRINTF(Branch, "[tid:%i]: Instruction %s no indirect " - "target.\n", tid, pc); + DPRINTF(Branch, + "[tid:%i] [sn:%llu] " + "Instruction %s no indirect " + "target\n", + tid, seqNum, pc); if (!inst->isCall() && !inst->isReturn()) { } else if (inst->isCall() && !inst->isUncondCtrl()) { @@ -330,8 +342,10 @@ BPredUnit::predict(const StaticInstPtr &inst, const InstSeqNum &seqNum, predHist[tid].push_front(predict_record); - DPRINTF(Branch, "[tid:%i]: [sn:%i]: History entry added." - "predHist.size(): %i\n", tid, seqNum, predHist[tid].size()); + DPRINTF(Branch, + "[tid:%i] [sn:%llu] History entry added. " + "predHist.size(): %i\n", + tid, seqNum, predHist[tid].size()); return pred_taken; } @@ -339,8 +353,8 @@ BPredUnit::predict(const StaticInstPtr &inst, const InstSeqNum &seqNum, void BPredUnit::update(const InstSeqNum &done_sn, ThreadID tid) { - DPRINTF(Branch, "[tid:%i]: Committing branches until " - "[sn:%lli].\n", tid, done_sn); + DPRINTF(Branch, "[tid:%i] Committing branches until " + "sn:%llu]\n", tid, done_sn); while (!predHist[tid].empty() && predHist[tid].back().seqNum <= done_sn) { @@ -371,16 +385,17 @@ BPredUnit::squash(const InstSeqNum &squashed_sn, ThreadID tid) while (!pred_hist.empty() && pred_hist.front().seqNum > squashed_sn) { if (pred_hist.front().usedRAS) { - DPRINTF(Branch, "[tid:%i]: Restoring top of RAS to: %i," - " target: %s.\n", tid, + DPRINTF(Branch, "[tid:%i] [squash sn:%llu]" + " Restoring top of RAS to: %i," + " target: %s\n", tid, squashed_sn, pred_hist.front().RASIndex, pred_hist.front().RASTarget); RAS[tid].restore(pred_hist.front().RASIndex, pred_hist.front().RASTarget); } else if (pred_hist.front().wasCall && pred_hist.front().pushedRAS) { // Was a call but predicated false. Pop RAS here - DPRINTF(Branch, "[tid: %i] Squashing" - " Call [sn:%i] PC: %s Popping RAS\n", tid, + DPRINTF(Branch, "[tid:%i] [squash sn:%llu] Squashing" + " Call [sn:%llu] PC: %s Popping RAS\n", tid, squashed_sn, pred_hist.front().seqNum, pred_hist.front().pc); RAS[tid].pop(); } @@ -391,14 +406,15 @@ BPredUnit::squash(const InstSeqNum &squashed_sn, ThreadID tid) iPred.deleteIndirectInfo(tid, pred_hist.front().indirectHistory); } - DPRINTF(Branch, "[tid:%i]: Removing history for [sn:%i] " - "PC %s.\n", tid, pred_hist.front().seqNum, + DPRINTF(Branch, "[tid:%i] [squash sn:%llu] " + "Removing history for [sn:%llu] " + "PC %#x\n", tid, squashed_sn, pred_hist.front().seqNum, pred_hist.front().pc); pred_hist.pop_front(); - DPRINTF(Branch, "[tid:%i]: predHist.size(): %i\n", - tid, predHist[tid].size()); + DPRINTF(Branch, "[tid:%i] [squash sn:%llu] predHist.size(): %i\n", + tid, squashed_sn, predHist[tid].size()); } } @@ -423,8 +439,8 @@ BPredUnit::squash(const InstSeqNum &squashed_sn, ++condIncorrect; ppMisses->notify(1); - DPRINTF(Branch, "[tid:%i]: Squashing from sequence number %i, " - "setting target to %s.\n", tid, squashed_sn, corrTarget); + DPRINTF(Branch, "[tid:%i] Squashing from sequence number %i, " + "setting target to %s\n", tid, squashed_sn, corrTarget); // Squash All Branches AFTER this mispredicted branch squash(squashed_sn, tid); @@ -449,8 +465,9 @@ BPredUnit::squash(const InstSeqNum &squashed_sn, if ((*hist_it).usedRAS) { ++RASIncorrect; - DPRINTF(Branch, "[tid:%i]: Incorrect RAS [sn:%i]\n", - tid, hist_it->seqNum); + DPRINTF(Branch, + "[tid:%i] [squash sn:%llu] Incorrect RAS [sn:%llu]\n", + tid, squashed_sn, hist_it->seqNum); } // There are separate functions for in-order and out-of-order @@ -477,9 +494,11 @@ BPredUnit::squash(const InstSeqNum &squashed_sn, if (actually_taken) { if (hist_it->wasReturn && !hist_it->usedRAS) { - DPRINTF(Branch, "[tid: %i] Incorrectly predicted" - " return [sn:%i] PC: %s\n", tid, hist_it->seqNum, - hist_it->pc); + DPRINTF(Branch, "[tid:%i] [squash sn:%llu] " + "Incorrectly predicted " + "return [sn:%llu] PC: %#x\n", tid, squashed_sn, + hist_it->seqNum, + hist_it->pc); RAS[tid].pop(); hist_it->usedRAS = true; } @@ -489,34 +508,42 @@ BPredUnit::squash(const InstSeqNum &squashed_sn, hist_it->seqNum, pred_hist.front().indirectHistory, corrTarget, tid); } else { - DPRINTF(Branch,"[tid: %i] BTB Update called for [sn:%i]" - " PC: %s\n", tid,hist_it->seqNum, hist_it->pc); + DPRINTF(Branch,"[tid:%i] [squash sn:%llu] " + "BTB Update called for [sn:%llu] " + "PC %#x\n", tid, squashed_sn, + hist_it->seqNum, hist_it->pc); BTB.update((*hist_it).pc, corrTarget, tid); } } else { //Actually not Taken if (hist_it->usedRAS) { - DPRINTF(Branch,"[tid: %i] Incorrectly predicted" - " return [sn:%i] PC: %s Restoring RAS\n", tid, + DPRINTF(Branch, + "[tid:%i] [squash sn:%llu] Incorrectly predicted " + "return [sn:%llu] PC: %#x Restoring RAS\n", tid, + squashed_sn, hist_it->seqNum, hist_it->pc); - DPRINTF(Branch, "[tid:%i]: Restoring top of RAS" - " to: %i, target: %s.\n", tid, + DPRINTF(Branch, + "[tid:%i] [squash sn:%llu] Restoring top of RAS " + "to: %i, target: %s\n", tid, squashed_sn, hist_it->RASIndex, hist_it->RASTarget); RAS[tid].restore(hist_it->RASIndex, hist_it->RASTarget); hist_it->usedRAS = false; } else if (hist_it->wasCall && hist_it->pushedRAS) { //Was a Call but predicated false. Pop RAS here - DPRINTF(Branch, "[tid: %i] Incorrectly predicted" - " Call [sn:%i] PC: %s Popping RAS\n", tid, - hist_it->seqNum, hist_it->pc); + DPRINTF(Branch, + "[tid:%i] [squash sn:%llu] " + "Incorrectly predicted " + "Call [sn:%llu] PC: %s Popping RAS\n", + tid, squashed_sn, + hist_it->seqNum, hist_it->pc); RAS[tid].pop(); hist_it->pushedRAS = false; } } } else { - DPRINTF(Branch, "[tid:%i]: [sn:%i] pred_hist empty, can't " - "update.\n", tid, squashed_sn); + DPRINTF(Branch, "[tid:%i] [sn:%llu] pred_hist empty, can't " + "update\n", tid, squashed_sn); } } @@ -531,7 +558,7 @@ BPredUnit::dump() cprintf("predHist[%i].size(): %i\n", i++, ph.size()); while (pred_hist_it != ph.end()) { - cprintf("[sn:%lli], PC:%#x, tid:%i, predTaken:%i, " + cprintf("sn:%llu], PC:%#x, tid:%i, predTaken:%i, " "bpHistory:%#x\n", pred_hist_it->seqNum, pred_hist_it->pc, pred_hist_it->tid, pred_hist_it->predTaken,