diff --git a/Grid/algorithms/multigrid/BlockCyclicSchurInverse.h b/Grid/algorithms/multigrid/BlockCyclicSchurInverse.h index c459abfd7..ce00004d1 100644 --- a/Grid/algorithms/multigrid/BlockCyclicSchurInverse.h +++ b/Grid/algorithms/multigrid/BlockCyclicSchurInverse.h @@ -397,6 +397,25 @@ public: << " gemm min/max " << gmin << "/" << gmax << " | ring bytes/rank " << gb << " GB -> " << (ring>0 ? gb/ring : 0.0) << " GB/s/rank (boss)" << std::endl; + // Ring time decomposed by message size (boss rank; every rank sends the + // same sequence of sizes). Time is wall time inside SendToRecvFrom, so it + // includes waiting for the partner -- a bucket whose GB/s is far below the + // probe's for the same size is wait, not wire. + std::cout << GridLogMessage << "BlockCyclicSumma ring histogram (boss): size-bucket msgs GB secs GB/s %time" << std::endl; + std::streamsize oldprec = std::cout.precision(); + for(int b=0;b=1048576) snprintf(sz,32,"%6.1f MB",lo/1048576.); else if (lo>=1024) snprintf(sz,32,"%6.1f KB",lo/1024.); else snprintf(sz,32,"%6.0f B ",lo); + std::cout << GridLogMessage << " >=" << sz + << std::setw(8) << SUMMA.histN[b] + << std::setw(10) << std::setprecision(3) << g + << std::setw(9) << std::setprecision(3) << sec + << std::setw(9) << std::setprecision(3) << (sec>0 ? g/sec : 0.0) + << std::setw(8) << std::setprecision(3) << (ring>0 ? 100.0*sec/ring : 0.0) << std::endl; + } + std::cout.precision(oldprec); } }; diff --git a/Grid/algorithms/multigrid/BlockCyclicSumma.h b/Grid/algorithms/multigrid/BlockCyclicSumma.h index 33f3cefa0..ab5e7a876 100644 --- a/Grid/algorithms/multigrid/BlockCyclicSumma.h +++ b/Grid/algorithms/multigrid/BlockCyclicSumma.h @@ -143,7 +143,14 @@ public: deviceVector Bbuf; double tAlloc=0, tPack=0, tRingA=0, tRingB=0, tGemm=0; uint64_t bytesRing=0, nRingMsg=0, nMultiply=0, nGemm=0; - void ResetTelemetry(void){ tAlloc=tPack=tRingA=tRingB=tGemm=0; bytesRing=nRingMsg=nMultiply=nGemm=0; } + // Per-message-size histogram (bucket = floor(log2 bytes)): count, bytes, + // microseconds -- decomposes the ring time by packet size so a low average + // GB/s can be attributed (many small latency-bound messages vs slow large + // ones vs partner-wait). The 8 MB probe runs at 11-20 GB/s; SUMMA averaged 2. + static const int NHIST=48; + uint64_t histN[NHIST]={0}, histBytes[NHIST]={0}; double histUs[NHIST]={0}; + void HistAdd(uint64_t bytes, double us){ int b=0; while((bytes>>b)>1) b++; histN[b]++; histBytes[b]+=bytes; histUs[b]+=us; } + void ResetTelemetry(void){ tAlloc=tPack=tRingA=tRingB=tGemm=0; bytesRing=nRingMsg=nMultiply=nGemm=0; for(int b=0;bSendToRecvFrom((void *)(&Abuf[0]+slotA*cs), dest, (void *)(&Abuf[0]+slotA*cr), src, slotA*sizeof(ComplexD)); + HistAdd(slotA*sizeof(ComplexD), usecond()-tm); bytesRing += slotA*sizeof(ComplexD); nRingMsg++; } tRingA += usecond(); @@ -291,9 +300,11 @@ public: for(int t=1;tSendToRecvFrom((void *)(&Bbuf[0]+slotB*rs), dest, (void *)(&Bbuf[0]+slotB*rr), src, slotB*sizeof(ComplexD)); + HistAdd(slotB*sizeof(ComplexD), usecond()-tm); bytesRing += slotB*sizeof(ComplexD); nRingMsg++; } tRingB += usecond();