From a8fbfefb5e0fd3b45d6961b07a172018c87c0251 Mon Sep 17 00:00:00 2001 From: Uri Wiener Date: Mon, 22 Apr 2013 13:20:33 -0400 Subject: [PATCH] mem: Adding verbose debug output in the memory system This patch provides useful printouts throughut the memory system. This includes pretty-printed cache tags and function call messages (call-stack like). --- src/mem/abstract_mem.cc | 5 ++- src/mem/cache/SConscript | 1 + src/mem/cache/blk.hh | 36 ++++++++++++++++++++++ src/mem/cache/cache_impl.hh | 60 +++++++++++++++++++++++++++--------- src/mem/cache/mshr.cc | 22 +++++++++++++ src/mem/cache/mshr.hh | 19 ++++++++++++ src/mem/cache/tags/base.hh | 5 +++ src/mem/cache/tags/fa_lru.hh | 5 +++ src/mem/cache/tags/lru.cc | 30 ++++++++++++++++++ src/mem/cache/tags/lru.hh | 5 +++ src/mem/coherent_bus.cc | 3 ++ src/mem/packet.cc | 9 +++++- src/mem/packet.hh | 8 +++++ src/mem/packet_queue.cc | 2 ++ 14 files changed, 194 insertions(+), 16 deletions(-) diff --git a/src/mem/abstract_mem.cc b/src/mem/abstract_mem.cc index fb8b7d81b..b25b32616 100644 --- a/src/mem/abstract_mem.cc +++ b/src/mem/abstract_mem.cc @@ -363,8 +363,11 @@ AbstractMemory::access(PacketPtr pkt) bytesInstRead[pkt->req->masterId()] += pkt->getSize(); } else if (pkt->isWrite()) { if (writeOK(pkt)) { - if (pmemAddr) + if (pmemAddr) { memcpy(hostAddr, pkt->getPtr(), pkt->getSize()); + DPRINTF(MemoryAccess, "%s wrote %x bytes to address %x\n", + __func__, pkt->getSize(), pkt->getAddr()); + } assert(!pkt->req->isInstFetch()); TRACE_PACKET("Write"); numWrites[pkt->req->masterId()]++; diff --git a/src/mem/cache/SConscript b/src/mem/cache/SConscript index dc2270b08..e7b0dca0c 100644 --- a/src/mem/cache/SConscript +++ b/src/mem/cache/SConscript @@ -45,4 +45,5 @@ Source('mshr_queue.cc') DebugFlag('Cache') DebugFlag('CachePort') DebugFlag('CacheRepl') +DebugFlag('CacheTags') DebugFlag('HWPrefetch') diff --git a/src/mem/cache/blk.hh b/src/mem/cache/blk.hh index 80216ff89..4a89f3892 100644 --- a/src/mem/cache/blk.hh +++ b/src/mem/cache/blk.hh @@ -288,6 +288,42 @@ class CacheBlk } } + /** + * Pretty-print a tag, and interpret state bits to readable form + * including mapping to a MOESI stat. + * + * @return string with basic state information + */ + std::string print() const + { + /** + * state M O E S I + * writable 1 0 1 0 0 + * dirty 1 1 0 0 0 + * valid 1 1 1 1 0 + * + * state writable dirty valid + * M 1 1 1 + * O 0 1 1 + * E 1 0 1 + * S 0 0 1 + * I 0 0 0 + **/ + unsigned state = isWritable() << 2 | isDirty() << 1 | isValid(); + char s = '?'; + switch (state) { + case 0b111: s = 'M'; break; + case 0b011: s = 'O'; break; + case 0b101: s = 'E'; break; + case 0b001: s = 'S'; break; + case 0b000: s = 'I'; break; + default: s = 'T'; break; // @TODO add other types + } + return csprintf("state: %x (%c) valid: %d writable: %d readable: %d " + "dirty: %d tag: %x data: %x", status, s, isValid(), + isWritable(), isReadable(), isDirty(), tag, *data); + } + /** * Handle interaction of load-locked operations and stores. * @return True if write should proceed, false otherwise. Returns diff --git a/src/mem/cache/cache_impl.hh b/src/mem/cache/cache_impl.hh index 68b86b121..3ebb4eb70 100644 --- a/src/mem/cache/cache_impl.hh +++ b/src/mem/cache/cache_impl.hh @@ -55,6 +55,7 @@ #include "base/types.hh" #include "debug/Cache.hh" #include "debug/CachePort.hh" +#include "debug/CacheTags.hh" #include "mem/cache/prefetch/base.hh" #include "mem/cache/blk.hh" #include "mem/cache/cache.hh" @@ -278,6 +279,8 @@ bool Cache::access(PacketPtr pkt, BlkType *&blk, Cycles &lat, PacketList &writebacks) { + DPRINTF(Cache, "%s for %s address %x size %d\n", __func__, + pkt->cmdString(), pkt->getAddr(), pkt->getSize()); if (pkt->req->isUncacheable()) { uncacheableFlush(pkt); blk = NULL; @@ -288,9 +291,9 @@ Cache::access(PacketPtr pkt, BlkType *&blk, int id = pkt->req->hasContextId() ? pkt->req->contextId() : -1; blk = tags->accessBlock(pkt->getAddr(), lat, id); - DPRINTF(Cache, "%s%s %x %s\n", pkt->cmdString(), + DPRINTF(Cache, "%s%s %x %s %s\n", pkt->cmdString(), pkt->req->isInstFetch() ? " (ifetch)" : "", - pkt->getAddr(), (blk) ? "hit" : "miss"); + pkt->getAddr(), blk ? "hit" : "miss", blk ? blk->print() : ""); if (blk != NULL) { @@ -330,6 +333,7 @@ Cache::access(PacketPtr pkt, BlkType *&blk, } // nothing else to do; writeback doesn't expect response assert(!pkt->needsResponse()); + DPRINTF(Cache, "%s new state is %s\n", __func__, blk->print()); incHitCount(pkt); return true; } @@ -360,6 +364,8 @@ template void Cache::recvTimingSnoopResp(PacketPtr pkt) { + DPRINTF(Cache, "%s for %s address %x size %d\n", __func__, + pkt->cmdString(), pkt->getAddr(), pkt->getSize()); Tick time = clockEdge(hitLatency); assert(pkt->isResponse()); @@ -391,6 +397,7 @@ template bool Cache::recvTimingReq(PacketPtr pkt) { + DPRINTF(CacheTags, "%s tags: %s\n", __func__, tags->print()); //@todo Add back in MemDebug Calls // MemDebug::cacheAccess(pkt); @@ -630,6 +637,8 @@ Cache::getBusPacket(PacketPtr cpu_pkt, BlkType *blk, PacketPtr pkt = new Packet(cpu_pkt->req, cmd, blkSize); pkt->allocate(); + DPRINTF(Cache, "%s created %s address %x size %d\n", + __func__, pkt->cmdString(), pkt->getAddr(), pkt->getSize()); return pkt; } @@ -850,7 +859,8 @@ Cache::recvTimingResp(PacketPtr pkt) "cmd: %s\n", pkt->getAddr(), pkt->cmdString()); } - DPRINTF(Cache, "Handling response to %x\n", pkt->getAddr()); + DPRINTF(Cache, "Handling response to %s for address %x\n", + pkt->cmdString(), pkt->getAddr()); MSHRQueue *mq = mshr->queue; bool wasFull = mq->isFull(); @@ -959,6 +969,9 @@ Cache::recvTimingResp(PacketPtr pkt) // propagate that. Response should not have // isInvalidate() set otherwise. target->pkt->cmd = MemCmd::ReadRespWithInvalidate; + DPRINTF(Cache, "%s updated cmd to %s for address %x\n", + __func__, target->pkt->cmdString(), + target->pkt->getAddr()); } // reset the bus additional time as it is now accounted for target->pkt->busFirstWordDelay = target->pkt->busLastWordDelay = 0; @@ -1031,6 +1044,8 @@ Cache::recvTimingResp(PacketPtr pkt) blk->invalidate(); } + DPRINTF(Cache, "Leaving %s with %s for address %x\n", __func__, + pkt->cmdString(), pkt->getAddr()); delete pkt; } @@ -1234,8 +1249,8 @@ Cache::handleFill(PacketPtr pkt, BlkType *blk, blk->status |= BlkDirty; } - DPRINTF(Cache, "Block addr %x moving from state %i to %i\n", - addr, old_state, blk->status); + DPRINTF(Cache, "Block addr %x moving from state %x to %s\n", + addr, old_state, blk->print()); // if we got new data, copy it in if (pkt->isRead()) { @@ -1261,6 +1276,8 @@ Cache:: doTimingSupplyResponse(PacketPtr req_pkt, uint8_t *blk_data, bool already_copied, bool pending_inval) { + DPRINTF(Cache, "%s for %s address %x size %d\n", __func__, + req_pkt->cmdString(), req_pkt->getAddr(), req_pkt->getSize()); // timing-mode snoop responses require a new packet, unless we // already made a copy... PacketPtr pkt = already_copied ? req_pkt : new Packet(req_pkt); @@ -1282,6 +1299,8 @@ doTimingSupplyResponse(PacketPtr req_pkt, uint8_t *blk_data, // invalidate it. pkt->cmd = MemCmd::ReadRespWithInvalidate; } + DPRINTF(Cache, "%s created response: %s address %x size %d\n", + __func__, pkt->cmdString(), pkt->getAddr(), pkt->getSize()); memSidePort->schedTimingSnoopResp(pkt, clockEdge(hitLatency)); } @@ -1291,6 +1310,8 @@ Cache::handleSnoop(PacketPtr pkt, BlkType *blk, bool is_timing, bool is_deferred, bool pending_inval) { + DPRINTF(Cache, "%s for %s address %x size %d\n", __func__, + pkt->cmdString(), pkt->getAddr(), pkt->getSize()); // deferred snoops can only happen in timing mode assert(!(is_deferred && !is_timing)); // pending_inval only makes sense on deferred snoops @@ -1336,9 +1357,15 @@ Cache::handleSnoop(PacketPtr pkt, BlkType *blk, } } - if (!blk || !blk->isValid()) { - return; - } + if (!blk || !blk->isValid()) { + DPRINTF(Cache, "%s snoop miss for %s address %x size %d\n", + __func__, pkt->cmdString(), pkt->getAddr(), pkt->getSize()); + return; + } else { + DPRINTF(Cache, "%s snoop hit for %s for address %x size %d, " + "old state is %s\n", __func__, pkt->cmdString(), + pkt->getAddr(), pkt->getSize(), blk->print()); + } // we may end up modifying both the block state and the packet (if // we respond in atomic mode), so just figure out what to do now @@ -1360,10 +1387,6 @@ Cache::handleSnoop(PacketPtr pkt, BlkType *blk, blk->status &= ~bits_to_clear; } - DPRINTF(Cache, "snooped a %s request for addr %x, %snew state is %i\n", - pkt->cmdString(), blockAlign(pkt->getAddr()), - respond ? "responding, " : "", invalidate ? 0 : blk->status); - if (respond) { assert(!pkt->memInhibitAsserted()); pkt->assertMemInhibit(); @@ -1390,6 +1413,8 @@ Cache::handleSnoop(PacketPtr pkt, BlkType *blk, tags->invalidate(blk); blk->invalidate(); } + + DPRINTF(Cache, "new state is %s\n", blk->print()); } @@ -1397,6 +1422,9 @@ template void Cache::recvTimingSnoopReq(PacketPtr pkt) { + DPRINTF(Cache, "%s for %s address %x size %d\n", __func__, + pkt->cmdString(), pkt->getAddr(), pkt->getSize()); + // Snoops shouldn't happen when bypassing caches assert(!system->bypassCaches()); @@ -1417,8 +1445,9 @@ Cache::recvTimingSnoopReq(PacketPtr pkt) // Let the MSHR itself track the snoop and decide whether we want // to go ahead and do the regular cache snoop if (mshr && mshr->handleSnoop(pkt, order++)) { - DPRINTF(Cache, "Deferring snoop on in-service MSHR to blk %x\n", - blk_addr); + DPRINTF(Cache, "Deferring snoop on in-service MSHR to blk %x." + "mshrs: %s\n", blk_addr, mshr->print()); + if (mshr->getNumTargets() > numTarget) warn("allocating bonus target for snoop"); //handle later return; @@ -1598,6 +1627,9 @@ Cache::getTimingPacket() PacketPtr tgt_pkt = mshr->getTarget()->pkt; PacketPtr pkt = NULL; + DPRINTF(CachePort, "%s %s for address %x size %d\n", __func__, + tgt_pkt->cmdString(), tgt_pkt->getAddr(), tgt_pkt->getSize()); + if (tgt_pkt->cmd == MemCmd::SCUpgradeFailReq || tgt_pkt->cmd == MemCmd::StoreCondFailReq) { // SCUpgradeReq or StoreCondReq saw invalidation while queued diff --git a/src/mem/cache/mshr.cc b/src/mem/cache/mshr.cc index 86e2bebad..32c87324b 100644 --- a/src/mem/cache/mshr.cc +++ b/src/mem/cache/mshr.cc @@ -1,4 +1,16 @@ /* + * Copyright (c) 2012 ARM Limited + * All rights reserved. + * + * The license below extends only to copyright in the software and shall + * not be construed as granting a license to any other intellectual + * property including but not limited to intellectual property relating + * to a hardware implementation of the functionality of the software + * licensed hereunder. You may use the software subject to the license + * terms below provided that you ensure that this notice is replicated + * unmodified and in its entirety in all distributions of the software, + * modified or unmodified, in source code or in binary form. + * * Copyright (c) 2002-2005 The Regents of The University of Michigan * Copyright (c) 2010 Advanced Micro Devices, Inc. * All rights reserved. @@ -303,6 +315,8 @@ MSHR::allocateTarget(PacketPtr pkt, Tick whenReady, Counter _order) bool MSHR::handleSnoop(PacketPtr pkt, Counter _order) { + DPRINTF(Cache, "%s for %s address %x size %d\n", __func__, + pkt->cmdString(), pkt->getAddr(), pkt->getSize()); if (!inService || (pkt->isExpressSnoop() && downstreamPending)) { // Request has not been issued yet, or it's been issued // locally but is buffered unissued at some downstream cache @@ -467,6 +481,14 @@ MSHR::print(std::ostream &os, int verbosity, const std::string &prefix) const } } +std::string +MSHR::print() const +{ + ostringstream str; + print(str); + return str.str(); +} + MSHR::~MSHR() { delete[] targets; diff --git a/src/mem/cache/mshr.hh b/src/mem/cache/mshr.hh index 87e561ac7..f99a293fd 100644 --- a/src/mem/cache/mshr.hh +++ b/src/mem/cache/mshr.hh @@ -1,4 +1,16 @@ /* + * Copyright (c) 2012 ARM Limited + * All rights reserved. + * + * The license below extends only to copyright in the software and shall + * not be construed as granting a license to any other intellectual + * property including but not limited to intellectual property relating + * to a hardware implementation of the functionality of the software + * licensed hereunder. You may use the software subject to the license + * terms below provided that you ensure that this notice is replicated + * unmodified and in its entirety in all distributions of the software, + * modified or unmodified, in source code or in binary form. + * * Copyright (c) 2002-2005 The Regents of The University of Michigan * All rights reserved. * @@ -279,6 +291,13 @@ public: void print(std::ostream &os, int verbosity = 0, const std::string &prefix = "") const; + /** + * A no-args wrapper of print(std::ostream...) meant to be + * invoked from DPRINTFs avoiding string overheads in fast mode + * + * @return string with mshr fields + [deferred]targets + */ + std::string print() const; }; #endif //__MSHR_HH__ diff --git a/src/mem/cache/tags/base.hh b/src/mem/cache/tags/base.hh index 3539f2bfd..aae442636 100644 --- a/src/mem/cache/tags/base.hh +++ b/src/mem/cache/tags/base.hh @@ -159,6 +159,11 @@ class BaseTags *Needed to clear all lock tracking at once */ virtual void clearLocks() {} + + /** + * Print all tags used + */ + virtual std::string print() const = 0; }; class BaseTagsCallback : public Callback diff --git a/src/mem/cache/tags/fa_lru.hh b/src/mem/cache/tags/fa_lru.hh index 7604d8d43..3c8cc5bec 100644 --- a/src/mem/cache/tags/fa_lru.hh +++ b/src/mem/cache/tags/fa_lru.hh @@ -300,6 +300,11 @@ public: */ virtual void clearLocks(); + /** + * @todo Implement as in lru. Currently not used + */ + virtual std::string print() const { return ""; } + /** * Visit each block in the tag store and apply a visitor to the * block. diff --git a/src/mem/cache/tags/lru.cc b/src/mem/cache/tags/lru.cc index 00b13e2d8..f515ed053 100644 --- a/src/mem/cache/tags/lru.cc +++ b/src/mem/cache/tags/lru.cc @@ -1,4 +1,16 @@ /* + * Copyright (c) 2012 ARM Limited + * All rights reserved. + * + * The license below extends only to copyright in the software and shall + * not be construed as granting a license to any other intellectual + * property including but not limited to intellectual property relating + * to a hardware implementation of the functionality of the software + * licensed hereunder. You may use the software subject to the license + * terms below provided that you ensure that this notice is replicated + * unmodified and in its entirety in all distributions of the software, + * modified or unmodified, in source code or in binary form. + * * Copyright (c) 2003-2005 The Regents of The University of Michigan * All rights reserved. * @@ -36,6 +48,7 @@ #include #include "base/intmath.hh" +#include "debug/Cache.hh" #include "debug/CacheRepl.hh" #include "mem/cache/tags/cacheset.hh" #include "mem/cache/tags/lru.hh" @@ -226,6 +239,23 @@ LRU::clearLocks() } } +std::string +LRU::print() const { + std::string cache_state; + for (unsigned i = 0; i < numSets; ++i) { + // link in the data blocks + for (unsigned j = 0; j < assoc; ++j) { + BlkType *blk = sets[i].blks[j]; + if (blk->isValid()) + cache_state += csprintf("\tset: %d block: %d %s\n", i, j, + blk->print()); + } + } + if (cache_state.empty()) + cache_state = "no valid tags\n"; + return cache_state; +} + void LRU::cleanupRefs() { diff --git a/src/mem/cache/tags/lru.hh b/src/mem/cache/tags/lru.hh index 431e3eb1e..2e44aa84f 100644 --- a/src/mem/cache/tags/lru.hh +++ b/src/mem/cache/tags/lru.hh @@ -248,6 +248,11 @@ public: */ virtual void cleanupRefs(); + /** + * Print all tags used + */ + virtual std::string print() const; + /** * Visit each block in the tag store and apply a visitor to the * block. diff --git a/src/mem/coherent_bus.cc b/src/mem/coherent_bus.cc index 8bc183fd0..5f7153d2f 100644 --- a/src/mem/coherent_bus.cc +++ b/src/mem/coherent_bus.cc @@ -337,6 +337,9 @@ CoherentBus::recvTimingSnoopResp(PacketPtr pkt, PortID slave_port_id) void CoherentBus::forwardTiming(PacketPtr pkt, PortID exclude_slave_port_id) { + DPRINTF(CoherentBus, "%s for %s address %x size %d\n", __func__, + pkt->cmdString(), pkt->getAddr(), pkt->getSize()); + // snoops should only happen if the system isn't bypassing caches assert(!system->bypassCaches()); diff --git a/src/mem/packet.cc b/src/mem/packet.cc index cea65cea0..a4ee1e56a 100644 --- a/src/mem/packet.cc +++ b/src/mem/packet.cc @@ -1,5 +1,5 @@ /* - * Copyright (c) 2011 ARM Limited + * Copyright (c) 2011-2012 ARM Limited * All rights reserved * * The license below extends only to copyright in the software and shall @@ -340,6 +340,13 @@ Packet::print(ostream &o, const int verbosity, const string &prefix) const getAddr(), getAddr() + getSize() - 1, cmdString()); } +std::string +Packet::print() const { + ostringstream str; + print(str); + return str.str(); +} + Packet::PrintReqState::PrintReqState(ostream &_os, int _verbosity) : curPrefixPtr(new string("")), os(_os), verbosity(_verbosity) { diff --git a/src/mem/packet.hh b/src/mem/packet.hh index 92fb2a31c..fa7070f2e 100644 --- a/src/mem/packet.hh +++ b/src/mem/packet.hh @@ -923,6 +923,14 @@ class Packet : public Printable void print(std::ostream &o, int verbosity = 0, const std::string &prefix = "") const; + + /** + * A no-args wrapper of print(std::ostream...) + * meant to be invoked from DPRINTFs + * avoiding string overheads in fast mode + * @return string with the request's type and start<->end addresses + */ + std::string print() const; }; #endif //__MEM_PACKET_HH diff --git a/src/mem/packet_queue.cc b/src/mem/packet_queue.cc index e60e77453..a6f31c6eb 100644 --- a/src/mem/packet_queue.cc +++ b/src/mem/packet_queue.cc @@ -107,6 +107,8 @@ PacketQueue::schedSendEvent(Tick when) void PacketQueue::schedSendTiming(PacketPtr pkt, Tick when, bool send_as_snoop) { + DPRINTF(PacketQueue, "%s for %s address %x size %d\n", __func__, + pkt->cmdString(), pkt->getAddr(), pkt->getSize()); // we can still send a packet before the end of this tick assert(when >= curTick()); -- 2.30.2