From: Steve Reinhardt Date: Thu, 31 Dec 2015 17:32:09 +0000 (-0800) Subject: mem: add CacheVerbose debug flag, filter noisy DPRINTFs X-Git-Url: https://git.libre-soc.org/?a=commitdiff_plain;h=6caa2c9b4ea8ed3a29c44dec60b791344b5fd477;p=gem5.git mem: add CacheVerbose debug flag, filter noisy DPRINTFs Some of the DPRINTFs added to the classic cache in cset 45df88079f04, while useful to those unfamiliar with the cache code, end up being noise when you're familiar with the code but are trying to debug tricky protocol issues. (Particularly getting two messages from each cache as it receives a snoop request then declares that there was no match.) This patch introduces a CacheVerbose debug flag, and moves a subset of the added DPRINTFs into that category, so that Cache by itself returns to being a more succinct summary of cache activity. Also added a CacheAll compound flag to turn on all the cache-related debug flags (other than CacheTags, which you *really* have to want badly to turn it on, IMO). --- diff --git a/src/mem/cache/SConscript b/src/mem/cache/SConscript index 1c356ef6a..01f099f1b 100644 --- a/src/mem/cache/SConscript +++ b/src/mem/cache/SConscript @@ -42,4 +42,12 @@ DebugFlag('Cache') DebugFlag('CachePort') DebugFlag('CacheRepl') DebugFlag('CacheTags') +DebugFlag('CacheVerbose') DebugFlag('HWPrefetch') + +# CacheTags is so outrageously verbose, printing the cache's entire tag +# array on each timing access, that you should probably have to ask for +# it explicitly even above and beyond CacheAll. +CompoundFlag('CacheAll', ['Cache', 'CachePort', 'CacheRepl', 'CacheVerbose', + 'HWPrefetch']) + diff --git a/src/mem/cache/cache.cc b/src/mem/cache/cache.cc index 9050a1c30..294f807ba 100644 --- a/src/mem/cache/cache.cc +++ b/src/mem/cache/cache.cc @@ -58,6 +58,7 @@ #include "debug/Cache.hh" #include "debug/CachePort.hh" #include "debug/CacheTags.hh" +#include "debug/CacheVerbose.hh" #include "mem/cache/blk.hh" #include "mem/cache/mshr.hh" #include "mem/cache/prefetch/base.hh" @@ -179,8 +180,8 @@ Cache::satisfyCpuSideRequest(PacketPtr pkt, CacheBlk *blk, // supply data to any snoops that have appended themselves to // this cache before knowing the store will fail. blk->status |= BlkDirty; - DPRINTF(Cache, "%s for %s addr %#llx size %d (write)\n", __func__, - pkt->cmdString(), pkt->getAddr(), pkt->getSize()); + DPRINTF(CacheVerbose, "%s for %s addr %#llx size %d (write)\n", + __func__, pkt->cmdString(), pkt->getAddr(), pkt->getSize()); } else if (pkt->isRead()) { if (pkt->isLLSC()) { blk->trackLoadLocked(pkt); @@ -280,7 +281,7 @@ Cache::satisfyCpuSideRequest(PacketPtr pkt, CacheBlk *blk, // for invalidations we could be looking at the temp block // (for upgrades we always allocate) invalidateBlock(blk); - DPRINTF(Cache, "%s for %s addr %#llx size %d (invalidation)\n", + DPRINTF(CacheVerbose, "%s for %s addr %#llx size %d (invalidation)\n", __func__, pkt->cmdString(), pkt->getAddr(), pkt->getSize()); } } @@ -316,7 +317,7 @@ Cache::access(PacketPtr pkt, CacheBlk *&blk, Cycles &lat, "Should never see a write in a read-only cache %s\n", name()); - DPRINTF(Cache, "%s for %s addr %#llx size %d\n", __func__, + DPRINTF(CacheVerbose, "%s for %s addr %#llx size %d\n", __func__, pkt->cmdString(), pkt->getAddr(), pkt->getSize()); if (pkt->req->isUncacheable()) { @@ -1222,7 +1223,7 @@ Cache::functionalAccess(PacketPtr pkt, bool fromCpuSide) || writeBuffer.checkFunctional(pkt, blk_addr) || memSidePort->checkFunctional(pkt); - DPRINTF(Cache, "functional %s %#llx (%s) %s%s%s\n", + DPRINTF(CacheVerbose, "functional %s %#llx (%s) %s%s%s\n", pkt->cmdString(), pkt->getAddr(), is_secure ? "s" : "ns", (blk && blk->isValid()) ? "valid " : "", have_data ? "data " : "", done ? "done " : ""); @@ -1533,7 +1534,7 @@ Cache::recvTimingResp(PacketPtr pkt) blk->invalidate(); } - DPRINTF(Cache, "Leaving %s with %s for addr %#llx\n", __func__, + DPRINTF(CacheVerbose, "Leaving %s with %s for addr %#llx\n", __func__, pkt->cmdString(), pkt->getAddr()); delete pkt; } @@ -1881,7 +1882,8 @@ Cache::doTimingSupplyResponse(PacketPtr req_pkt, const uint8_t *blk_data, Tick forward_time = clockEdge(forwardLatency) + pkt->headerDelay; // Here we reset the timing of the packet. pkt->headerDelay = pkt->payloadDelay = 0; - DPRINTF(Cache, "%s created response: %s addr %#llx size %d tick: %lu\n", + DPRINTF(CacheVerbose, + "%s created response: %s addr %#llx size %d tick: %lu\n", __func__, pkt->cmdString(), pkt->getAddr(), pkt->getSize(), forward_time); memSidePort->schedTimingSnoopResp(pkt, forward_time, true); @@ -1891,7 +1893,7 @@ uint32_t Cache::handleSnoop(PacketPtr pkt, CacheBlk *blk, bool is_timing, bool is_deferred, bool pending_inval) { - DPRINTF(Cache, "%s for %s addr %#llx size %d\n", __func__, + DPRINTF(CacheVerbose, "%s for %s addr %#llx size %d\n", __func__, pkt->cmdString(), pkt->getAddr(), pkt->getSize()); // deferred snoops can only happen in timing mode assert(!(is_deferred && !is_timing)); @@ -1963,13 +1965,13 @@ Cache::handleSnoop(PacketPtr pkt, CacheBlk *blk, bool is_timing, } if (!blk || !blk->isValid()) { - DPRINTF(Cache, "%s snoop miss for %s addr %#llx size %d\n", + DPRINTF(CacheVerbose, "%s snoop miss for %s addr %#llx size %d\n", __func__, pkt->cmdString(), pkt->getAddr(), pkt->getSize()); return snoop_delay; } else { - DPRINTF(Cache, "%s snoop hit for %s for addr %#llx size %d, " - "old state is %s\n", __func__, pkt->cmdString(), - pkt->getAddr(), pkt->getSize(), blk->print()); + DPRINTF(Cache, "%s snoop hit for %s addr %#llx size %d, " + "old state is %s\n", __func__, pkt->cmdString(), + pkt->getAddr(), pkt->getSize(), blk->print()); } chatty_assert(!(isReadOnly && blk->isDirty()), @@ -2073,7 +2075,7 @@ Cache::handleSnoop(PacketPtr pkt, CacheBlk *blk, bool is_timing, void Cache::recvTimingSnoopReq(PacketPtr pkt) { - DPRINTF(Cache, "%s for %s addr %#llx size %d\n", __func__, + DPRINTF(CacheVerbose, "%s for %s addr %#llx size %d\n", __func__, pkt->cmdString(), pkt->getAddr(), pkt->getSize()); // Snoops shouldn't happen when bypassing caches