sanchayanmaity/gem5
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity

mem: Make packet debug printing more uniform

Browse source 
Previously DPRINTFs printing information about a packet would use ad hoc
formats. This patch changes all DPRINTFs to use the print function
defined by the packet class, making the packet printing format more
uniform and easier to change.

Change-Id: Idd436a9758d4bf70c86a574d524648b2a2580970
Reviewed-by: Andreas Hansson <andreas.hansson@arm.com>
Reviewed-by: Stephan Diestelhorst <stephan.diestelhorst@arm.com>
This commit is contained in:
Nikos Nikoleris 2016-12-05 16:48:21 -05:00
parent 61860f2419
commit e16967941b
6 changed files with 119 additions and 167 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

3
src/mem/cache/base.hh vendored
View file

@ -518,8 +518,7 @@ class BaseCache : public MemObject
WriteQueueEntry *wq_entry = WriteQueueEntry *wq_entry =
writeBuffer.findMatch(blk_addr, pkt->isSecure()); writeBuffer.findMatch(blk_addr, pkt->isSecure());
if (wq_entry && !wq_entry->inService) { if (wq_entry && !wq_entry->inService) {
DPRINTF(Cache, "Potential to merge writeback %s to %#llx", DPRINTF(Cache, "Potential to merge writeback %s", pkt->print());
pkt->cmdString(), pkt->getAddr());
} }
writeBuffer.allocate(blk_addr, blkSize, pkt, time, order++); writeBuffer.allocate(blk_addr, blkSize, pkt, time, order++);

143
src/mem/cache/cache.cc vendored
View file

@ -180,8 +180,7 @@ Cache::satisfyRequest(PacketPtr pkt, CacheBlk *blk,
// supply data to any snoops that have appended themselves to // supply data to any snoops that have appended themselves to
// this cache before knowing the store will fail. // this cache before knowing the store will fail.
blk->status |= BlkDirty; blk->status |= BlkDirty;
DPRINTF(CacheVerbose, "%s for %s addr %#llx size %d (write)\n", DPRINTF(CacheVerbose, "%s for %s (write)\n", __func__, pkt->print());
__func__, pkt->cmdString(), pkt->getAddr(), pkt->getSize());
} else if (pkt->isRead()) { } else if (pkt->isRead()) {
if (pkt->isLLSC()) { if (pkt->isLLSC()) {
blk->trackLoadLocked(pkt); blk->trackLoadLocked(pkt);
@ -272,8 +271,8 @@ Cache::satisfyRequest(PacketPtr pkt, CacheBlk *blk,
} else { } else {
assert(pkt->isInvalidate()); assert(pkt->isInvalidate());
invalidateBlock(blk); invalidateBlock(blk);
DPRINTF(CacheVerbose, "%s for %s addr %#llx size %d (invalidation)\n", DPRINTF(CacheVerbose, "%s for %s (invalidation)\n", __func__,
__func__, pkt->cmdString(), pkt->getAddr(), pkt->getSize()); pkt->print());
} }
} }
@ -294,13 +293,10 @@ Cache::access(PacketPtr pkt, CacheBlk *&blk, Cycles &lat,
"Should never see a write in a read-only cache %s\n", "Should never see a write in a read-only cache %s\n",
name()); name());
DPRINTF(CacheVerbose, "%s for %s addr %#llx size %d\n", __func__, DPRINTF(CacheVerbose, "%s for %s\n", __func__, pkt->print());
pkt->cmdString(), pkt->getAddr(), pkt->getSize());
if (pkt->req->isUncacheable()) { if (pkt->req->isUncacheable()) {
DPRINTF(Cache, "%s%s addr %#llx uncacheable\n", pkt->cmdString(), DPRINTF(Cache, "uncacheable: %s\n", pkt->print());
pkt->req->isInstFetch() ? " (ifetch)" : "",
pkt->getAddr());
// flush and invalidate any existing block // flush and invalidate any existing block
CacheBlk *old_blk(tags->findBlock(pkt->getAddr(), pkt->isSecure())); CacheBlk *old_blk(tags->findBlock(pkt->getAddr(), pkt->isSecure()));
@ -325,9 +321,7 @@ Cache::access(PacketPtr pkt, CacheBlk *&blk, Cycles &lat,
// that can modify its value. // that can modify its value.
blk = tags->accessBlock(pkt->getAddr(), pkt->isSecure(), lat, id); blk = tags->accessBlock(pkt->getAddr(), pkt->isSecure(), lat, id);
DPRINTF(Cache, "%s%s addr %#llx size %d (%s) %s\n", pkt->cmdString(), DPRINTF(Cache, "%s %s\n", pkt->print(),
pkt->req->isInstFetch() ? " (ifetch)" : "",
pkt->getAddr(), pkt->getSize(), pkt->isSecure() ? "s" : "ns",
blk ? "hit " + blk->print() : "miss"); blk ? "hit " + blk->print() : "miss");
@ -543,8 +537,7 @@ Cache::doWritebacksAtomic(PacketList& writebacks)
void void
Cache::recvTimingSnoopResp(PacketPtr pkt) Cache::recvTimingSnoopResp(PacketPtr pkt)
{ {
DPRINTF(Cache, "%s for %s addr %#llx size %d\n", __func__, DPRINTF(Cache, "%s for %s\n", __func__, pkt->print());
pkt->cmdString(), pkt->getAddr(), pkt->getSize());
assert(pkt->isResponse()); assert(pkt->isResponse());
assert(!system->bypassCaches()); assert(!system->bypassCaches());
@ -610,9 +603,8 @@ Cache::recvTimingReq(PacketPtr pkt)
// a cache above us (but not where the packet came from) is // a cache above us (but not where the packet came from) is
// responding to the request, in other words it has the line // responding to the request, in other words it has the line
// in Modified or Owned state // in Modified or Owned state
DPRINTF(Cache, "Cache above responding to %#llx (%s): " DPRINTF(Cache, "Cache above responding to %s: not responding\n",
"not responding\n", pkt->print());
pkt->getAddr(), pkt->isSecure() ? "s" : "ns");
// if the packet needs the block to be writable, and the cache // if the packet needs the block to be writable, and the cache
// that has promised to respond (setting the cache responding // that has promised to respond (setting the cache responding
@ -736,8 +728,8 @@ Cache::recvTimingReq(PacketPtr pkt)
// by access(), that calls accessBlock() function. // by access(), that calls accessBlock() function.
cpuSidePort->schedTimingResp(pkt, request_time, true); cpuSidePort->schedTimingResp(pkt, request_time, true);
} else { } else {
DPRINTF(Cache, "%s satisfied %s addr %#llx, no response needed\n", DPRINTF(Cache, "%s satisfied %s, no response needed\n", __func__,
__func__, pkt->cmdString(), pkt->getAddr()); pkt->print());
// queue the packet for deletion, as the sending cache is // queue the packet for deletion, as the sending cache is
// still relying on it; if the block is found in access(), // still relying on it; if the block is found in access(),
@ -813,9 +805,8 @@ Cache::recvTimingReq(PacketPtr pkt)
if (pkt->cmd == MemCmd::CleanEvict) { if (pkt->cmd == MemCmd::CleanEvict) {
pendingDelete.reset(pkt); pendingDelete.reset(pkt);
} else { } else {
DPRINTF(Cache, "%s coalescing MSHR for %s addr %#llx " DPRINTF(Cache, "%s coalescing MSHR for %s\n", __func__,
"size %d\n", __func__, pkt->cmdString(), pkt->print());
pkt->getAddr(), pkt->getSize());
assert(pkt->req->masterId() < system->maxMasters()); assert(pkt->req->masterId() < system->maxMasters());
mshr_hits[pkt->cmdToIndex()][pkt->req->masterId()]++; mshr_hits[pkt->cmdToIndex()][pkt->req->masterId()]++;
@ -967,19 +958,16 @@ Cache::createMissPacket(PacketPtr cpu_pkt, CacheBlk *blk,
// of date, however, there is no harm in conservatively // of date, however, there is no harm in conservatively
// assuming the block has sharers // assuming the block has sharers
pkt->setHasSharers(); pkt->setHasSharers();
DPRINTF(Cache, "%s passing hasSharers from %s to %s addr %#llx " DPRINTF(Cache, "%s: passing hasSharers from %s to %s\n",
"size %d\n", __func__, cpu_pkt->print(), pkt->print());
__func__, cpu_pkt->cmdString(), pkt->cmdString(),
pkt->getAddr(), pkt->getSize());
} }
// the packet should be block aligned // the packet should be block aligned
assert(pkt->getAddr() == blockAlign(pkt->getAddr())); assert(pkt->getAddr() == blockAlign(pkt->getAddr()));
pkt->allocate(); pkt->allocate();
DPRINTF(Cache, "%s created %s from %s for addr %#llx size %d\n", DPRINTF(Cache, "%s: created %s from %s\n", __func__, pkt->print(),
__func__, pkt->cmdString(), cpu_pkt->cmdString(), pkt->getAddr(), cpu_pkt->print());
pkt->getSize());
return pkt; return pkt;
} }
@ -999,9 +987,8 @@ Cache::recvAtomic(PacketPtr pkt)
// follow the same flow as in recvTimingReq, and check if a cache // follow the same flow as in recvTimingReq, and check if a cache
// above us is responding // above us is responding
if (pkt->cacheResponding()) { if (pkt->cacheResponding()) {
DPRINTF(Cache, "Cache above responding to %#llx (%s): " DPRINTF(Cache, "Cache above responding to %s: not responding\n",
"not responding\n", pkt->print());
pkt->getAddr(), pkt->isSecure() ? "s" : "ns");
// if a cache is responding, and it had the line in Owned // if a cache is responding, and it had the line in Owned
// rather than Modified state, we need to invalidate any // rather than Modified state, we need to invalidate any
@ -1046,9 +1033,8 @@ Cache::recvAtomic(PacketPtr pkt)
bus_pkt = pkt; bus_pkt = pkt;
} }
DPRINTF(Cache, "Sending an atomic %s for %#llx (%s)\n", DPRINTF(Cache, "%s: Sending an atomic %s\n", __func__,
bus_pkt->cmdString(), bus_pkt->getAddr(), bus_pkt->print());
bus_pkt->isSecure() ? "s" : "ns");
#if TRACING_ON #if TRACING_ON
CacheBlk::State old_state = blk ? blk->status : 0; CacheBlk::State old_state = blk ? blk->status : 0;
@ -1059,10 +1045,8 @@ Cache::recvAtomic(PacketPtr pkt)
bool is_invalidate = bus_pkt->isInvalidate(); bool is_invalidate = bus_pkt->isInvalidate();
// We are now dealing with the response handling // We are now dealing with the response handling
DPRINTF(Cache, "Receive response: %s for addr %#llx (%s) in " DPRINTF(Cache, "%s: Receive response: %s in state %i\n", __func__,
"state %i\n", bus_pkt->cmdString(), bus_pkt->getAddr(), bus_pkt->print(), old_state);
bus_pkt->isSecure() ? "s" : "ns",
old_state);
// If packet was a forward, the response (if any) is already // If packet was a forward, the response (if any) is already
// in place in the bus_pkt == pkt structure, so we don't need // in place in the bus_pkt == pkt structure, so we don't need
@ -1198,8 +1182,7 @@ Cache::functionalAccess(PacketPtr pkt, bool fromCpuSide)
|| writeBuffer.checkFunctional(pkt, blk_addr) || writeBuffer.checkFunctional(pkt, blk_addr)
|| memSidePort->checkFunctional(pkt); || memSidePort->checkFunctional(pkt);
DPRINTF(CacheVerbose, "functional %s %#llx (%s) %s%s%s\n", DPRINTF(CacheVerbose, "%s: %s %s%s%s\n", __func__, pkt->print(),
pkt->cmdString(), pkt->getAddr(), is_secure ? "s" : "ns",
(blk && blk->isValid()) ? "valid " : "", (blk && blk->isValid()) ? "valid " : "",
have_data ? "data " : "", done ? "done " : ""); have_data ? "data " : "", done ? "done " : "");
@ -1254,14 +1237,12 @@ Cache::recvTimingResp(PacketPtr pkt)
bool is_error = pkt->isError(); bool is_error = pkt->isError();
if (is_error) { if (is_error) {
DPRINTF(Cache, "Cache received packet with error for addr %#llx (%s), " DPRINTF(Cache, "%s: Cache received %s with error\n", __func__,
"cmd: %s\n", pkt->getAddr(), pkt->isSecure() ? "s" : "ns", pkt->print());
pkt->cmdString());
} }
DPRINTF(Cache, "Handling response %s for addr %#llx size %d (%s)\n", DPRINTF(Cache, "%s: Handling response %s\n", __func__,
pkt->cmdString(), pkt->getAddr(), pkt->getSize(), pkt->print());
pkt->isSecure() ? "s" : "ns");
// if this is a write, we should be looking at an uncacheable // if this is a write, we should be looking at an uncacheable
// write // write
@ -1434,8 +1415,8 @@ Cache::recvTimingResp(PacketPtr pkt)
// propagate that. Response should not have // propagate that. Response should not have
// isInvalidate() set otherwise. // isInvalidate() set otherwise.
tgt_pkt->cmd = MemCmd::ReadRespWithInvalidate; tgt_pkt->cmd = MemCmd::ReadRespWithInvalidate;
DPRINTF(Cache, "%s updated cmd to %s for addr %#llx\n", DPRINTF(Cache, "%s: updated cmd to %s\n", __func__,
__func__, tgt_pkt->cmdString(), tgt_pkt->getAddr()); tgt_pkt->print());
} }
// Reset the bus additional time as it is now accounted for // Reset the bus additional time as it is now accounted for
tgt_pkt->headerDelay = tgt_pkt->payloadDelay = 0; tgt_pkt->headerDelay = tgt_pkt->payloadDelay = 0;
@ -1530,8 +1511,7 @@ Cache::recvTimingResp(PacketPtr pkt)
blk->invalidate(); blk->invalidate();
} }
DPRINTF(CacheVerbose, "Leaving %s with %s for addr %#llx\n", __func__, DPRINTF(CacheVerbose, "%s: Leaving with %s\n", __func__, pkt->print());
pkt->cmdString(), pkt->getAddr());
delete pkt; delete pkt;
} }
@ -1557,8 +1537,8 @@ Cache::writebackBlk(CacheBlk *blk)
new Packet(req, blk->isDirty() ? new Packet(req, blk->isDirty() ?
MemCmd::WritebackDirty : MemCmd::WritebackClean); MemCmd::WritebackDirty : MemCmd::WritebackClean);
DPRINTF(Cache, "Create Writeback %#llx writable: %d, dirty: %d\n", DPRINTF(Cache, "Create Writeback %s writable: %d, dirty: %d\n",
pkt->getAddr(), blk->isWritable(), blk->isDirty()); pkt->print(), blk->isWritable(), blk->isDirty());
if (blk->isWritable()) { if (blk->isWritable()) {
// not asserting shared means we pass the block in modified // not asserting shared means we pass the block in modified
@ -1596,9 +1576,7 @@ Cache::cleanEvictBlk(CacheBlk *blk)
PacketPtr pkt = new Packet(req, MemCmd::CleanEvict); PacketPtr pkt = new Packet(req, MemCmd::CleanEvict);
pkt->allocate(); pkt->allocate();
DPRINTF(Cache, "%s%s %x Create CleanEvict\n", pkt->cmdString(), DPRINTF(Cache, "Create CleanEvict %s\n", pkt->print());
pkt->req->isInstFetch() ? " (ifetch)" : "",
pkt->getAddr());
return pkt; return pkt;
} }
@ -1846,8 +1824,7 @@ Cache::doTimingSupplyResponse(PacketPtr req_pkt, const uint8_t *blk_data,
assert(req_pkt->isRequest()); assert(req_pkt->isRequest());
assert(req_pkt->needsResponse()); assert(req_pkt->needsResponse());
DPRINTF(Cache, "%s for %s addr %#llx size %d\n", __func__, DPRINTF(Cache, "%s: for %s\n", __func__, req_pkt->print());
req_pkt->cmdString(), req_pkt->getAddr(), req_pkt->getSize());
// timing-mode snoop responses require a new packet, unless we // timing-mode snoop responses require a new packet, unless we
// already made a copy... // already made a copy...
PacketPtr pkt = req_pkt; PacketPtr pkt = req_pkt;
@ -1879,10 +1856,8 @@ Cache::doTimingSupplyResponse(PacketPtr req_pkt, const uint8_t *blk_data,
Tick forward_time = clockEdge(forwardLatency) + pkt->headerDelay; Tick forward_time = clockEdge(forwardLatency) + pkt->headerDelay;
// Here we reset the timing of the packet. // Here we reset the timing of the packet.
pkt->headerDelay = pkt->payloadDelay = 0; pkt->headerDelay = pkt->payloadDelay = 0;
DPRINTF(CacheVerbose, DPRINTF(CacheVerbose, "%s: created response: %s tick: %lu\n", __func__,
"%s created response: %s addr %#llx size %d tick: %lu\n", pkt->print(), forward_time);
__func__, pkt->cmdString(), pkt->getAddr(), pkt->getSize(),
forward_time);
memSidePort->schedTimingSnoopResp(pkt, forward_time, true); memSidePort->schedTimingSnoopResp(pkt, forward_time, true);
} }
@ -1890,8 +1865,7 @@ uint32_t
Cache::handleSnoop(PacketPtr pkt, CacheBlk *blk, bool is_timing, Cache::handleSnoop(PacketPtr pkt, CacheBlk *blk, bool is_timing,
bool is_deferred, bool pending_inval) bool is_deferred, bool pending_inval)
{ {
DPRINTF(CacheVerbose, "%s for %s addr %#llx size %d\n", __func__, DPRINTF(CacheVerbose, "%s: for %s\n", __func__, pkt->print());
pkt->cmdString(), pkt->getAddr(), pkt->getSize());
// deferred snoops can only happen in timing mode // deferred snoops can only happen in timing mode
assert(!(is_deferred && !is_timing)); assert(!(is_deferred && !is_timing));
// pending_inval only makes sense on deferred snoops // pending_inval only makes sense on deferred snoops
@ -1908,8 +1882,8 @@ Cache::handleSnoop(PacketPtr pkt, CacheBlk *blk, bool is_timing,
// have the invalidate flag, and we need a suitable way of dealing // have the invalidate flag, and we need a suitable way of dealing
// with this case // with this case
panic_if(invalidate && pkt->req->isUncacheable(), panic_if(invalidate && pkt->req->isUncacheable(),
"%s got an invalidating uncacheable snoop request %s to %#llx", "%s got an invalidating uncacheable snoop request %s",
name(), pkt->cmdString(), pkt->getAddr()); name(), pkt->print());
uint32_t snoop_delay = 0; uint32_t snoop_delay = 0;
@ -1962,6 +1936,8 @@ Cache::handleSnoop(PacketPtr pkt, CacheBlk *blk, bool is_timing,
} }
if (!blk || !blk->isValid()) { if (!blk || !blk->isValid()) {
DPRINTF(CacheVerbose, "%s: snoop miss for %s\n", __func__,
pkt->print());
if (is_deferred) { if (is_deferred) {
// we no longer have the block, and will not respond, but a // we no longer have the block, and will not respond, but a
// packet was allocated in MSHR::handleSnoop and we have // packet was allocated in MSHR::handleSnoop and we have
@ -1974,14 +1950,10 @@ Cache::handleSnoop(PacketPtr pkt, CacheBlk *blk, bool is_timing,
delete pkt; delete pkt;
} }
DPRINTF(CacheVerbose, "%s snoop miss for %s addr %#llx size %d\n",
__func__, pkt->cmdString(), pkt->getAddr(), pkt->getSize());
return snoop_delay; return snoop_delay;
} else { } else {
DPRINTF(Cache, "%s snoop hit for %s addr %#llx size %d, " DPRINTF(Cache, "%s: snoop hit for %s, old state is %s\n", __func__,
"old state is %s\n", __func__, pkt->cmdString(), pkt->print(), blk->print());
pkt->getAddr(), pkt->getSize(), blk->print());
} }
chatty_assert(!(isReadOnly && blk->isDirty()), chatty_assert(!(isReadOnly && blk->isDirty()),
@ -2003,7 +1975,7 @@ Cache::handleSnoop(PacketPtr pkt, CacheBlk *blk, bool is_timing,
// downstream caches observe. // downstream caches observe.
if (pkt->mustCheckAbove()) { if (pkt->mustCheckAbove()) {
DPRINTF(Cache, "Found addr %#llx in upper level cache for snoop %s " DPRINTF(Cache, "Found addr %#llx in upper level cache for snoop %s "
"from lower cache\n", pkt->getAddr(), pkt->cmdString()); "from lower cache\n", pkt->getAddr(), pkt->print());
pkt->setBlockCached(); pkt->setBlockCached();
return snoop_delay; return snoop_delay;
} }
@ -2046,9 +2018,8 @@ Cache::handleSnoop(PacketPtr pkt, CacheBlk *blk, bool is_timing,
// if we are returning a writable and dirty (Modified) line, // if we are returning a writable and dirty (Modified) line,
// we should be invalidating the line // we should be invalidating the line
panic_if(!invalidate && !pkt->hasSharers(), panic_if(!invalidate && !pkt->hasSharers(),
"%s is passing a Modified line through %s to %#llx, " "%s is passing a Modified line through %s, "
"but keeping the block", "but keeping the block", name(), pkt->print());
name(), pkt->cmdString(), pkt->getAddr());
if (is_timing) { if (is_timing) {
doTimingSupplyResponse(pkt, blk->data, is_deferred, pending_inval); doTimingSupplyResponse(pkt, blk->data, is_deferred, pending_inval);
@ -2090,8 +2061,7 @@ Cache::handleSnoop(PacketPtr pkt, CacheBlk *blk, bool is_timing,
void void
Cache::recvTimingSnoopReq(PacketPtr pkt) Cache::recvTimingSnoopReq(PacketPtr pkt)
{ {
DPRINTF(CacheVerbose, "%s for %s addr %#llx size %d\n", __func__, DPRINTF(CacheVerbose, "%s: for %s\n", __func__, pkt->print());
pkt->cmdString(), pkt->getAddr(), pkt->getSize());
// Snoops shouldn't happen when bypassing caches // Snoops shouldn't happen when bypassing caches
assert(!system->bypassCaches()); assert(!system->bypassCaches());
@ -2118,9 +2088,8 @@ Cache::recvTimingSnoopReq(PacketPtr pkt)
// Inform request(Prefetch, CleanEvict or Writeback) from below of // Inform request(Prefetch, CleanEvict or Writeback) from below of
// MSHR hit, set setBlockCached. // MSHR hit, set setBlockCached.
if (mshr && pkt->mustCheckAbove()) { if (mshr && pkt->mustCheckAbove()) {
DPRINTF(Cache, "Setting block cached for %s from" DPRINTF(Cache, "Setting block cached for %s from lower cache on "
"lower cache on mshr hit %#x\n", "mshr hit\n", pkt->print());
pkt->cmdString(), pkt->getAddr());
pkt->setBlockCached(); pkt->setBlockCached();
return; return;
} }
@ -2157,8 +2126,8 @@ Cache::recvTimingSnoopReq(PacketPtr pkt)
// propagate the BLOCK_CACHED flag in Writeback packets and prevent // propagate the BLOCK_CACHED flag in Writeback packets and prevent
// any CleanEvicts from travelling down the memory hierarchy. // any CleanEvicts from travelling down the memory hierarchy.
pkt->setBlockCached(); pkt->setBlockCached();
DPRINTF(Cache, "Squashing %s from lower cache on writequeue hit" DPRINTF(Cache, "%s: Squashing %s from lower cache on writequeue "
" %#x\n", pkt->cmdString(), pkt->getAddr()); "hit\n", __func__, pkt->print());
return; return;
} }
@ -2370,9 +2339,7 @@ Cache::sendMSHRQueuePacket(MSHR* mshr)
// use request from 1st target // use request from 1st target
PacketPtr tgt_pkt = mshr->getTarget()->pkt; PacketPtr tgt_pkt = mshr->getTarget()->pkt;
DPRINTF(Cache, "%s MSHR %s for addr %#llx size %d\n", __func__, DPRINTF(Cache, "%s: MSHR %s\n", __func__, tgt_pkt->print());
tgt_pkt->cmdString(), tgt_pkt->getAddr(),
tgt_pkt->getSize());
CacheBlk *blk = tags->findBlock(mshr->blkAddr, mshr->isSecure); CacheBlk *blk = tags->findBlock(mshr->blkAddr, mshr->isSecure);
@ -2490,9 +2457,7 @@ Cache::sendWriteQueuePacket(WriteQueueEntry* wq_entry)
// always a single target for write queue entries // always a single target for write queue entries
PacketPtr tgt_pkt = wq_entry->getTarget()->pkt; PacketPtr tgt_pkt = wq_entry->getTarget()->pkt;
DPRINTF(Cache, "%s write %s for addr %#llx size %d\n", __func__, DPRINTF(Cache, "%s: write %s\n", __func__, tgt_pkt->print());
tgt_pkt->cmdString(), tgt_pkt->getAddr(),
tgt_pkt->getSize());
// forward as is, both for evictions and uncacheable writes // forward as is, both for evictions and uncacheable writes
if (!memSidePort->sendTimingReq(tgt_pkt)) { if (!memSidePort->sendTimingReq(tgt_pkt)) {

8
src/mem/cache/mshr.cc vendored
View file

@ -231,6 +231,7 @@ MSHR::TargetList::print(std::ostream &os, int verbosity,
} }
ccprintf(os, "%s%s: ", prefix, s); ccprintf(os, "%s%s: ", prefix, s);
t.pkt->print(os, verbosity, ""); t.pkt->print(os, verbosity, "");
ccprintf(os, "\n");
} }
} }
@ -343,15 +344,14 @@ MSHR::allocateTarget(PacketPtr pkt, Tick whenReady, Counter _order,
bool bool
MSHR::handleSnoop(PacketPtr pkt, Counter _order) MSHR::handleSnoop(PacketPtr pkt, Counter _order)
{ {
DPRINTF(Cache, "%s for %s addr %#llx size %d\n", __func__, DPRINTF(Cache, "%s for %s\n", __func__, pkt->print());
pkt->cmdString(), pkt->getAddr(), pkt->getSize());
// when we snoop packets the needsWritable and isInvalidate flags // when we snoop packets the needsWritable and isInvalidate flags
// should always be the same, however, this assumes that we never // should always be the same, however, this assumes that we never
// snoop writes as they are currently not marked as invalidations // snoop writes as they are currently not marked as invalidations
panic_if(pkt->needsWritable() != pkt->isInvalidate(), panic_if(pkt->needsWritable() != pkt->isInvalidate(),
"%s got snoop %s to addr %#llx where needsWritable, " "%s got snoop %s where needsWritable, "
"does not match isInvalidate", name(), pkt->cmdString(), "does not match isInvalidate", name(), pkt->print(),
pkt->getAddr()); pkt->getAddr());
if (!inService || (pkt->isExpressSnoop() && downstreamPending)) { if (!inService || (pkt->isExpressSnoop() && downstreamPending)) {

103
src/mem/coherent_xbar.cc
View file

@ -156,14 +156,13 @@ CoherentXBar::recvTimingReq(PacketPtr pkt, PortID slave_port_id)
// test if the crossbar should be considered occupied for the current // test if the crossbar should be considered occupied for the current
// port, and exclude express snoops from the check // port, and exclude express snoops from the check
if (!is_express_snoop && !reqLayers[master_port_id]->tryTiming(src_port)) { if (!is_express_snoop && !reqLayers[master_port_id]->tryTiming(src_port)) {
DPRINTF(CoherentXBar, "recvTimingReq: src %s %s 0x%x BUSY\n", DPRINTF(CoherentXBar, "%s: src %s packet %s BUSY\n", __func__,
src_port->name(), pkt->cmdString(), pkt->getAddr()); src_port->name(), pkt->print());
return false; return false;
} }
DPRINTF(CoherentXBar, "recvTimingReq: src %s %s expr %d 0x%x\n", DPRINTF(CoherentXBar, "%s: src %s packet %s\n", __func__,
src_port->name(), pkt->cmdString(), is_express_snoop, src_port->name(), pkt->print());
pkt->getAddr());
// store size and command as they might be modified when // store size and command as they might be modified when
// forwarding the packet // forwarding the packet
@ -194,10 +193,9 @@ CoherentXBar::recvTimingReq(PacketPtr pkt, PortID slave_port_id)
// the xbar has to be charged also with to lookup latency // the xbar has to be charged also with to lookup latency
// of the snoop filter // of the snoop filter
pkt->headerDelay += sf_res.second * clockPeriod(); pkt->headerDelay += sf_res.second * clockPeriod();
DPRINTF(CoherentXBar, "recvTimingReq: src %s %s 0x%x"\ DPRINTF(CoherentXBar, "%s: src %s packet %s SF size: %i lat: %i\n",
" SF size: %i lat: %i\n", src_port->name(), __func__, src_port->name(), pkt->print(),
pkt->cmdString(), pkt->getAddr(), sf_res.first.size(), sf_res.first.size(), sf_res.second);
sf_res.second);
if (pkt->isEviction()) { if (pkt->isEviction()) {
// for block-evicting packets, i.e. writebacks and // for block-evicting packets, i.e. writebacks and
@ -236,8 +234,8 @@ CoherentXBar::recvTimingReq(PacketPtr pkt, PortID slave_port_id)
// modify the address upon a sendTimingRequest // modify the address upon a sendTimingRequest
const Addr addr(pkt->getAddr()); const Addr addr(pkt->getAddr());
if (sink_packet) { if (sink_packet) {
DPRINTF(CoherentXBar, "Not forwarding %s to %#llx\n", DPRINTF(CoherentXBar, "%s: Not forwarding %s\n", __func__,
pkt->cmdString(), pkt->getAddr()); pkt->print());
} else { } else {
// determine if we are forwarding the packet, or responding to // determine if we are forwarding the packet, or responding to
// it // it
@ -277,8 +275,8 @@ CoherentXBar::recvTimingReq(PacketPtr pkt, PortID slave_port_id)
// restore the header delay // restore the header delay
pkt->headerDelay = old_header_delay; pkt->headerDelay = old_header_delay;
DPRINTF(CoherentXBar, "recvTimingReq: src %s %s 0x%x RETRY\n", DPRINTF(CoherentXBar, "%s: src %s packet %s RETRY\n", __func__,
src_port->name(), pkt->cmdString(), pkt->getAddr()); src_port->name(), pkt->print());
// update the layer state and schedule an idle event // update the layer state and schedule an idle event
reqLayers[master_port_id]->failedTiming(src_port, reqLayers[master_port_id]->failedTiming(src_port,
@ -363,13 +361,13 @@ CoherentXBar::recvTimingResp(PacketPtr pkt, PortID master_port_id)
// test if the crossbar should be considered occupied for the // test if the crossbar should be considered occupied for the
// current port // current port
if (!respLayers[slave_port_id]->tryTiming(src_port)) { if (!respLayers[slave_port_id]->tryTiming(src_port)) {
DPRINTF(CoherentXBar, "recvTimingResp: src %s %s 0x%x BUSY\n", DPRINTF(CoherentXBar, "%s: src %s packet %s BUSY\n", __func__,
src_port->name(), pkt->cmdString(), pkt->getAddr()); src_port->name(), pkt->print());
return false; return false;
} }
DPRINTF(CoherentXBar, "recvTimingResp: src %s %s 0x%x\n", DPRINTF(CoherentXBar, "%s: src %s packet %s\n", __func__,
src_port->name(), pkt->cmdString(), pkt->getAddr()); src_port->name(), pkt->print());
// store size and command as they might be modified when // store size and command as they might be modified when
// forwarding the packet // forwarding the packet
@ -412,9 +410,8 @@ CoherentXBar::recvTimingResp(PacketPtr pkt, PortID master_port_id)
void void
CoherentXBar::recvTimingSnoopReq(PacketPtr pkt, PortID master_port_id) CoherentXBar::recvTimingSnoopReq(PacketPtr pkt, PortID master_port_id)
{ {
DPRINTF(CoherentXBar, "recvTimingSnoopReq: src %s %s 0x%x\n", DPRINTF(CoherentXBar, "%s: src %s packet %s\n", __func__,
masterPorts[master_port_id]->name(), pkt->cmdString(), masterPorts[master_port_id]->name(), pkt->print());
pkt->getAddr());
// update stats here as we know the forwarding will succeed // update stats here as we know the forwarding will succeed
unsigned int pkt_size = pkt->hasData() ? pkt->getSize() : 0; unsigned int pkt_size = pkt->hasData() ? pkt->getSize() : 0;
@ -442,10 +439,9 @@ CoherentXBar::recvTimingSnoopReq(PacketPtr pkt, PortID master_port_id)
// the xbar has to be charged also with to lookup latency // the xbar has to be charged also with to lookup latency
// of the snoop filter // of the snoop filter
pkt->headerDelay += sf_res.second * clockPeriod(); pkt->headerDelay += sf_res.second * clockPeriod();
DPRINTF(CoherentXBar, "recvTimingSnoopReq: src %s %s 0x%x"\ DPRINTF(CoherentXBar, "%s: src %s packet %s SF size: %i lat: %i\n",
" SF size: %i lat: %i\n", masterPorts[master_port_id]->name(), __func__, masterPorts[master_port_id]->name(), pkt->print(),
pkt->cmdString(), pkt->getAddr(), sf_res.first.size(), sf_res.first.size(), sf_res.second);
sf_res.second);
// forward to all snoopers // forward to all snoopers
forwardTiming(pkt, InvalidPortID, sf_res.first); forwardTiming(pkt, InvalidPortID, sf_res.first);
@ -497,8 +493,8 @@ CoherentXBar::recvTimingSnoopResp(PacketPtr pkt, PortID slave_port_id)
if (forwardAsSnoop) { if (forwardAsSnoop) {
assert(dest_port_id < snoopLayers.size()); assert(dest_port_id < snoopLayers.size());
if (!snoopLayers[dest_port_id]->tryTiming(src_port)) { if (!snoopLayers[dest_port_id]->tryTiming(src_port)) {
DPRINTF(CoherentXBar, "recvTimingSnoopResp: src %s %s 0x%x BUSY\n", DPRINTF(CoherentXBar, "%s: src %s packet %s BUSY\n", __func__,
src_port->name(), pkt->cmdString(), pkt->getAddr()); src_port->name(), pkt->print());
return false; return false;
} }
} else { } else {
@ -506,14 +502,14 @@ CoherentXBar::recvTimingSnoopResp(PacketPtr pkt, PortID slave_port_id)
MasterPort* snoop_port = snoopRespPorts[slave_port_id]; MasterPort* snoop_port = snoopRespPorts[slave_port_id];
assert(dest_port_id < respLayers.size()); assert(dest_port_id < respLayers.size());
if (!respLayers[dest_port_id]->tryTiming(snoop_port)) { if (!respLayers[dest_port_id]->tryTiming(snoop_port)) {
DPRINTF(CoherentXBar, "recvTimingSnoopResp: src %s %s 0x%x BUSY\n", DPRINTF(CoherentXBar, "%s: src %s packet %s BUSY\n", __func__,
snoop_port->name(), pkt->cmdString(), pkt->getAddr()); snoop_port->name(), pkt->print());
return false; return false;
} }
} }
DPRINTF(CoherentXBar, "recvTimingSnoopResp: src %s %s 0x%x\n", DPRINTF(CoherentXBar, "%s: src %s packet %s\n", __func__,
src_port->name(), pkt->cmdString(), pkt->getAddr()); src_port->name(), pkt->print());
// store size and command as they might be modified when // store size and command as they might be modified when
// forwarding the packet // forwarding the packet
@ -572,9 +568,8 @@ CoherentXBar::recvTimingSnoopResp(PacketPtr pkt, PortID slave_port_id)
*slavePorts[dest_port_id]); *slavePorts[dest_port_id]);
} }
DPRINTF(CoherentXBar, "recvTimingSnoopResp: src %s %s 0x%x"\ DPRINTF(CoherentXBar, "%s: src %s packet %s FWD RESP\n", __func__,
" FWD RESP\n", src_port->name(), pkt->cmdString(), src_port->name(), pkt->print());
pkt->getAddr());
// as a normal response, it should go back to a master through // as a normal response, it should go back to a master through
// one of our slave ports, we also pay for any outstanding // one of our slave ports, we also pay for any outstanding
@ -602,8 +597,7 @@ void
CoherentXBar::forwardTiming(PacketPtr pkt, PortID exclude_slave_port_id, CoherentXBar::forwardTiming(PacketPtr pkt, PortID exclude_slave_port_id,
const std::vector<QueuedSlavePort*>& dests) const std::vector<QueuedSlavePort*>& dests)
{ {
DPRINTF(CoherentXBar, "%s for %s address %x size %d\n", __func__, DPRINTF(CoherentXBar, "%s for %s\n", __func__, pkt->print());
pkt->cmdString(), pkt->getAddr(), pkt->getSize());
// snoops should only happen if the system isn't bypassing caches // snoops should only happen if the system isn't bypassing caches
assert(!system->bypassCaches()); assert(!system->bypassCaches());
@ -639,9 +633,8 @@ CoherentXBar::recvReqRetry(PortID master_port_id)
Tick Tick
CoherentXBar::recvAtomic(PacketPtr pkt, PortID slave_port_id) CoherentXBar::recvAtomic(PacketPtr pkt, PortID slave_port_id)
{ {
DPRINTF(CoherentXBar, "recvAtomic: packet src %s addr 0x%x cmd %s\n", DPRINTF(CoherentXBar, "%s: src %s packet %s\n", __func__,
slavePorts[slave_port_id]->name(), pkt->getAddr(), slavePorts[slave_port_id]->name(), pkt->print());
pkt->cmdString());
unsigned int pkt_size = pkt->hasData() ? pkt->getSize() : 0; unsigned int pkt_size = pkt->hasData() ? pkt->getSize() : 0;
unsigned int pkt_cmd = pkt->cmdToIndex(); unsigned int pkt_cmd = pkt->cmdToIndex();
@ -657,10 +650,9 @@ CoherentXBar::recvAtomic(PacketPtr pkt, PortID slave_port_id)
auto sf_res = auto sf_res =
snoopFilter->lookupRequest(pkt, *slavePorts[slave_port_id]); snoopFilter->lookupRequest(pkt, *slavePorts[slave_port_id]);
snoop_response_latency += sf_res.second * clockPeriod(); snoop_response_latency += sf_res.second * clockPeriod();
DPRINTF(CoherentXBar, "%s: src %s %s 0x%x"\ DPRINTF(CoherentXBar, "%s: src %s packet %s SF size: %i lat: %i\n",
" SF size: %i lat: %i\n", __func__, __func__, slavePorts[slave_port_id]->name(), pkt->print(),
slavePorts[slave_port_id]->name(), pkt->cmdString(), sf_res.first.size(), sf_res.second);
pkt->getAddr(), sf_res.first.size(), sf_res.second);
// let the snoop filter know about the success of the send // let the snoop filter know about the success of the send
// operation, and do it even before sending it onwards to // operation, and do it even before sending it onwards to
@ -687,8 +679,8 @@ CoherentXBar::recvAtomic(PacketPtr pkt, PortID slave_port_id)
PortID master_port_id = findPort(pkt->getAddr()); PortID master_port_id = findPort(pkt->getAddr());
if (sink_packet) { if (sink_packet) {
DPRINTF(CoherentXBar, "Not forwarding %s to %#llx\n", DPRINTF(CoherentXBar, "%s: Not forwarding %s\n", __func__,
pkt->cmdString(), pkt->getAddr()); pkt->print());
} else { } else {
if (!pointOfCoherency || pkt->isRead() || pkt->isWrite()) { if (!pointOfCoherency || pkt->isRead() || pkt->isWrite()) {
// forward the request to the appropriate destination // forward the request to the appropriate destination
@ -739,9 +731,8 @@ CoherentXBar::recvAtomic(PacketPtr pkt, PortID slave_port_id)
Tick Tick
CoherentXBar::recvAtomicSnoop(PacketPtr pkt, PortID master_port_id) CoherentXBar::recvAtomicSnoop(PacketPtr pkt, PortID master_port_id)
{ {
DPRINTF(CoherentXBar, "recvAtomicSnoop: packet src %s addr 0x%x cmd %s\n", DPRINTF(CoherentXBar, "%s: src %s packet %s\n", __func__,
masterPorts[master_port_id]->name(), pkt->getAddr(), masterPorts[master_port_id]->name(), pkt->print());
pkt->cmdString());
// add the request snoop data // add the request snoop data
unsigned int pkt_size = pkt->hasData() ? pkt->getSize() : 0; unsigned int pkt_size = pkt->hasData() ? pkt->getSize() : 0;
@ -754,9 +745,9 @@ CoherentXBar::recvAtomicSnoop(PacketPtr pkt, PortID master_port_id)
if (snoopFilter) { if (snoopFilter) {
auto sf_res = snoopFilter->lookupSnoop(pkt); auto sf_res = snoopFilter->lookupSnoop(pkt);
snoop_response_latency += sf_res.second * clockPeriod(); snoop_response_latency += sf_res.second * clockPeriod();
DPRINTF(CoherentXBar, "%s: src %s %s 0x%x SF size: %i lat: %i\n", DPRINTF(CoherentXBar, "%s: src %s packet %s SF size: %i lat: %i\n",
__func__, masterPorts[master_port_id]->name(), pkt->cmdString(), __func__, masterPorts[master_port_id]->name(), pkt->print(),
pkt->getAddr(), sf_res.first.size(), sf_res.second); sf_res.first.size(), sf_res.second);
snoop_result = forwardAtomic(pkt, InvalidPortID, master_port_id, snoop_result = forwardAtomic(pkt, InvalidPortID, master_port_id,
sf_res.first); sf_res.first);
} else { } else {
@ -854,10 +845,8 @@ CoherentXBar::recvFunctional(PacketPtr pkt, PortID slave_port_id)
{ {
if (!pkt->isPrint()) { if (!pkt->isPrint()) {
// don't do DPRINTFs on PrintReq as it clutters up the output // don't do DPRINTFs on PrintReq as it clutters up the output
DPRINTF(CoherentXBar, DPRINTF(CoherentXBar, "%s: src %s packet %s\n", __func__,
"recvFunctional: packet src %s addr 0x%x cmd %s\n", slavePorts[slave_port_id]->name(), pkt->print());
slavePorts[slave_port_id]->name(), pkt->getAddr(),
pkt->cmdString());
} }
if (!system->bypassCaches()) { if (!system->bypassCaches()) {
@ -891,10 +880,8 @@ CoherentXBar::recvFunctionalSnoop(PacketPtr pkt, PortID master_port_id)
{ {
if (!pkt->isPrint()) { if (!pkt->isPrint()) {
// don't do DPRINTFs on PrintReq as it clutters up the output // don't do DPRINTFs on PrintReq as it clutters up the output
DPRINTF(CoherentXBar, DPRINTF(CoherentXBar, "%s: src %s packet %s\n", __func__,
"recvFunctionalSnoop: packet src %s addr 0x%x cmd %s\n", masterPorts[master_port_id]->name(), pkt->print());
masterPorts[master_port_id]->name(), pkt->getAddr(),
pkt->cmdString());
} }
for (const auto& p : slavePorts) { for (const auto& p : slavePorts) {

8
src/mem/packet.cc
View file

@ -345,8 +345,12 @@ Packet::popSenderState()
void void
Packet::print(ostream &o, const int verbosity, const string &prefix) const Packet::print(ostream &o, const int verbosity, const string &prefix) const
{ {
ccprintf(o, "%s[%x:%x] %s\n", prefix, ccprintf(o, "%s%s [%x:%x]%s%s%s%s", prefix, cmdString(),
getAddr(), getAddr() + getSize() - 1, cmdString()); getAddr(), getAddr() + getSize() - 1,
req->isSecure() ? " (s)" : "",
req->isInstFetch() ? " IF" : "",
req->isUncacheable() ? " UC" : "",
isExpressSnoop() ? " ES" : "");
} }
std::string std::string

21
src/mem/snoop_filter.cc
View file

@ -62,8 +62,8 @@ SnoopFilter::eraseIfNullEntry(SnoopFilterCache::iterator& sf_it)
std::pair<SnoopFilter::SnoopList, Cycles> std::pair<SnoopFilter::SnoopList, Cycles>
SnoopFilter::lookupRequest(const Packet* cpkt, const SlavePort& slave_port) SnoopFilter::lookupRequest(const Packet* cpkt, const SlavePort& slave_port)
{ {
DPRINTF(SnoopFilter, "%s: packet src %s addr 0x%x cmd %s\n", DPRINTF(SnoopFilter, "%s: src %s packet %s\n", __func__,
__func__, slave_port.name(), cpkt->getAddr(), cpkt->cmdString()); slave_port.name(), cpkt->print());
// check if the packet came from a cache // check if the packet came from a cache
bool allocate = !cpkt->req->isUncacheable() && slave_port.isSnooping() && bool allocate = !cpkt->req->isUncacheable() && slave_port.isSnooping() &&
@ -176,8 +176,7 @@ SnoopFilter::finishRequest(bool will_retry, Addr addr, bool is_secure)
std::pair<SnoopFilter::SnoopList, Cycles> std::pair<SnoopFilter::SnoopList, Cycles>
SnoopFilter::lookupSnoop(const Packet* cpkt) SnoopFilter::lookupSnoop(const Packet* cpkt)
{ {
DPRINTF(SnoopFilter, "%s: packet addr 0x%x cmd %s\n", DPRINTF(SnoopFilter, "%s: packet %s\n", __func__, cpkt->print());
__func__, cpkt->getAddr(), cpkt->cmdString());
assert(cpkt->isRequest()); assert(cpkt->isRequest());
@ -238,9 +237,8 @@ SnoopFilter::updateSnoopResponse(const Packet* cpkt,
const SlavePort& rsp_port, const SlavePort& rsp_port,
const SlavePort& req_port) const SlavePort& req_port)
{ {
DPRINTF(SnoopFilter, "%s: packet rsp %s req %s addr 0x%x cmd %s\n", DPRINTF(SnoopFilter, "%s: rsp %s req %s packet %s\n",
__func__, rsp_port.name(), req_port.name(), cpkt->getAddr(), __func__, rsp_port.name(), req_port.name(), cpkt->print());
cpkt->cmdString());
assert(cpkt->isResponse()); assert(cpkt->isResponse());
assert(cpkt->cacheResponding()); assert(cpkt->cacheResponding());
@ -294,9 +292,8 @@ void
SnoopFilter::updateSnoopForward(const Packet* cpkt, SnoopFilter::updateSnoopForward(const Packet* cpkt,
const SlavePort& rsp_port, const MasterPort& req_port) const SlavePort& rsp_port, const MasterPort& req_port)
{ {
DPRINTF(SnoopFilter, "%s: packet rsp %s req %s addr 0x%x cmd %s\n", DPRINTF(SnoopFilter, "%s: rsp %s req %s packet %s\n",
__func__, rsp_port.name(), req_port.name(), cpkt->getAddr(), __func__, rsp_port.name(), req_port.name(), cpkt->print());
cpkt->cmdString());
assert(cpkt->isResponse()); assert(cpkt->isResponse());
assert(cpkt->cacheResponding()); assert(cpkt->cacheResponding());
@ -332,8 +329,8 @@ SnoopFilter::updateSnoopForward(const Packet* cpkt,
void void
SnoopFilter::updateResponse(const Packet* cpkt, const SlavePort& slave_port) SnoopFilter::updateResponse(const Packet* cpkt, const SlavePort& slave_port)
{ {
DPRINTF(SnoopFilter, "%s: packet src %s addr 0x%x cmd %s\n", DPRINTF(SnoopFilter, "%s: src %s packet %s\n",
__func__, slave_port.name(), cpkt->getAddr(), cpkt->cmdString()); __func__, slave_port.name(), cpkt->print());
assert(cpkt->isResponse()); assert(cpkt->isResponse());