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).
This commit is contained in:
Steve Reinhardt 2015-12-31 09:32:09 -08:00
parent c153b669fd
commit 6caa2c9b4e
2 changed files with 23 additions and 13 deletions

View file

@ -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'])

View file

@ -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