From 7b39c3d1ae6ad1102d699b76c4f869243649f406 Mon Sep 17 00:00:00 2001 From: Herb Derby Date: Tue, 16 Mar 2021 17:45:33 -0400 Subject: [PATCH] print telemetry for diagnosing text drawing problems in Chrome Dump information about the Difference, Serialization, Deserialization, and Drawing phases of Renderer/GPU text drawing. Add the following to your args.gn to turn on telemetry. extra_cflags = ["-D", "SK_TRACE_GLYPH_RUN_PROCESS"] Change-Id: If435257574b74910822dbb90cc9dbca311578fe8 Reviewed-on: https://skia-review.googlesource.com/c/skia/+/385696 Commit-Queue: Herb Derby Reviewed-by: Michael Ludwig --- src/core/SkDescriptor.cpp | 12 ++++++++ src/core/SkDescriptor.h | 2 ++ src/core/SkGlyphBuffer.cpp | 10 +++++++ src/core/SkGlyphBuffer.h | 2 ++ src/core/SkGlyphRunPainter.cpp | 50 ++++++++++++++++++++++++++++++++- src/core/SkGlyphRunPainter.h | 3 +- src/core/SkRemoteGlyphCache.cpp | 33 +++++++++++++++++++++- src/core/SkScalerContext.h | 8 +++--- src/core/SkStrikeSpec.cpp | 4 +++ src/core/SkStrikeSpec.h | 1 + src/gpu/text/GrTextBlob.cpp | 3 +- 11 files changed, 120 insertions(+), 8 deletions(-) diff --git a/src/core/SkDescriptor.cpp b/src/core/SkDescriptor.cpp index adf0133235..787fb29655 100644 --- a/src/core/SkDescriptor.cpp +++ b/src/core/SkDescriptor.cpp @@ -83,6 +83,18 @@ bool SkDescriptor::operator==(const SkDescriptor& other) const { return true; } +SkString SkDescriptor::dumpRec() const { + const SkScalerContextRec* rec = static_cast( + this->findEntry(kRec_SkDescriptorTag, nullptr)); + + SkString result; + result.appendf(" Checksum: %x\n", fChecksum); + if (rec != nullptr) { + result.append(rec->dump()); + } + return result; +} + uint32_t SkDescriptor::ComputeChecksum(const SkDescriptor* desc) { const uint32_t* ptr = (const uint32_t*)desc + 1; // skip the checksum field size_t len = desc->fLength - sizeof(uint32_t); diff --git a/src/core/SkDescriptor.h b/src/core/SkDescriptor.h index abbef1f4f1..3142908791 100644 --- a/src/core/SkDescriptor.h +++ b/src/core/SkDescriptor.h @@ -63,6 +63,8 @@ public: uint32_t getCount() const { return fCount; } #endif + SkString dumpRec() const; + private: SkDescriptor() = default; friend class SkDescriptorTestHelper; diff --git a/src/core/SkGlyphBuffer.cpp b/src/core/SkGlyphBuffer.cpp index 85ab918d49..182200b9fd 100644 --- a/src/core/SkGlyphBuffer.cpp +++ b/src/core/SkGlyphBuffer.cpp @@ -98,6 +98,16 @@ void SkDrawableGlyphBuffer::startGPUDevice( SkDEBUGCODE(fPhase = kInput); } +SkString SkDrawableGlyphBuffer::dumpInput() const { + SkASSERT(fPhase == kInput); + + SkString msg; + for (auto [packedGlyphID, pos] + : SkZip{fInputSize, fMultiBuffer.get(), fPositions.get()}) { + msg.appendf("0x%x:(%a,%a), ", packedGlyphID.packedID().value(), pos.x(), pos.y()); + } + return msg; +} void SkDrawableGlyphBuffer::reset() { SkDEBUGCODE(fPhase = kReset); diff --git a/src/core/SkGlyphBuffer.h b/src/core/SkGlyphBuffer.h index c7386eefc7..99e7ee7f5d 100644 --- a/src/core/SkGlyphBuffer.h +++ b/src/core/SkGlyphBuffer.h @@ -172,6 +172,8 @@ public: const SkMatrix& drawMatrix, const SkGlyphPositionRoundingSpec& roundingSpec); + SkString dumpInput() const; + // The input of SkPackedGlyphIDs SkZip input() { SkASSERT(fPhase == kInput); diff --git a/src/core/SkGlyphRunPainter.cpp b/src/core/SkGlyphRunPainter.cpp index 3c255a2355..0d98e47eb1 100644 --- a/src/core/SkGlyphRunPainter.cpp +++ b/src/core/SkGlyphRunPainter.cpp @@ -136,12 +136,25 @@ void SkGlyphRunListPainter::drawForBitmapDevice( } } +// Use the following in your args.gn to dump telemetry for diagnosing chrome Renderer/GPU +// differences. +// extra_cflags = ["-D", "SK_TRACE_GLYPH_RUN_PROCESS"] + #if SK_SUPPORT_GPU void SkGlyphRunListPainter::processGlyphRun(const SkGlyphRun& glyphRun, const SkMatrix& drawMatrix, const SkPaint& runPaint, const GrSDFTControl& control, - SkGlyphRunPainterInterface* process) { + SkGlyphRunPainterInterface* process, + const char* tag) { + #if defined(SK_TRACE_GLYPH_RUN_PROCESS) + SkString msg; + msg.appendf("\nStart glyph run processing"); + if (tag != nullptr) { + msg.appendf(" for %s ", tag); + } + msg.appendf("\n"); + #endif ScopedBuffers _ = this->ensureBuffers(glyphRun); fRejects.setSource(glyphRun.source()); const SkFont& runFont = glyphRun.font(); @@ -153,10 +166,17 @@ void SkGlyphRunListPainter::processGlyphRun(const SkGlyphRun& glyphRun, const auto& [strikeSpec, minScale, maxScale] = SkStrikeSpec::MakeSDFT(runFont, runPaint, fDeviceProps, drawMatrix, control); + #if defined(SK_TRACE_GLYPH_RUN_PROCESS) + msg.appendf(" SDFT case:\n%s", strikeSpec.dump().c_str()); + #endif + if (!strikeSpec.isEmpty()) { SkScopedStrikeForGPU strike = strikeSpec.findOrCreateScopedStrike(fStrikeCache); fDrawable.startSource(fRejects.source()); + #if defined(SK_TRACE_GLYPH_RUN_PROCESS) + msg.appendf(" glyphs:(x,y):\n %s\n", fDrawable.dumpInput().c_str()); + #endif strike->prepareForSDFTDrawing(&fDrawable, &fRejects); fRejects.flipRejectsToSource(); @@ -175,9 +195,16 @@ void SkGlyphRunListPainter::processGlyphRun(const SkGlyphRun& glyphRun, SkStrikeSpec strikeSpec = SkStrikeSpec::MakeMask( runFont, runPaint, fDeviceProps, fScalerContextFlags, drawMatrix); + #if defined(SK_TRACE_GLYPH_RUN_PROCESS) + msg.appendf(" Mask case:\n%s", strikeSpec.dump().c_str()); + #endif + SkScopedStrikeForGPU strike = strikeSpec.findOrCreateScopedStrike(fStrikeCache); fDrawable.startGPUDevice(fRejects.source(), drawMatrix, strike->roundingSpec()); + #if defined(SK_TRACE_GLYPH_RUN_PROCESS) + msg.appendf(" glyphs:(x,y):\n %s\n", fDrawable.dumpInput().c_str()); + #endif strike->prepareForMaskDrawing(&fDrawable, &fRejects); fRejects.flipRejectsToSource(); @@ -198,10 +225,17 @@ void SkGlyphRunListPainter::processGlyphRun(const SkGlyphRun& glyphRun, SkStrikeSpec strikeSpec = SkStrikeSpec::MakePath( runFont, runPaint, fDeviceProps, fScalerContextFlags); + #if defined(SK_TRACE_GLYPH_RUN_PROCESS) + msg.appendf(" Path case:\n%s", strikeSpec.dump().c_str()); + #endif + if (!strikeSpec.isEmpty()) { SkScopedStrikeForGPU strike = strikeSpec.findOrCreateScopedStrike(fStrikeCache); fDrawable.startSource(fRejects.source()); + #if defined(SK_TRACE_GLYPH_RUN_PROCESS) + msg.appendf(" glyphs:(x,y):\n %s\n", fDrawable.dumpInput().c_str()); + #endif strike->prepareForPathDrawing(&fDrawable, &fRejects); fRejects.flipRejectsToSource(); maxDimensionInSourceSpace = @@ -221,10 +255,17 @@ void SkGlyphRunListPainter::processGlyphRun(const SkGlyphRun& glyphRun, runFont, runPaint, fDeviceProps, fScalerContextFlags, maxDimensionInSourceSpace); + #if defined(SK_TRACE_GLYPH_RUN_PROCESS) + msg.appendf("Transformed case:\n%s", strikeSpec.dump().c_str()); + #endif + if (!strikeSpec.isEmpty()) { SkScopedStrikeForGPU strike = strikeSpec.findOrCreateScopedStrike(fStrikeCache); fDrawable.startSource(fRejects.source()); + #if defined(SK_TRACE_GLYPH_RUN_PROCESS) + msg.appendf("glyphs:(x,y):\n %s\n", fDrawable.dumpInput().c_str()); + #endif strike->prepareForMaskDrawing(&fDrawable, &fRejects); fRejects.flipRejectsToSource(); SkASSERT(fRejects.source().empty()); @@ -234,6 +275,13 @@ void SkGlyphRunListPainter::processGlyphRun(const SkGlyphRun& glyphRun, } } } + #if defined(SK_TRACE_GLYPH_RUN_PROCESS) + msg.appendf("End glyph run processing"); + if (tag != nullptr) { + msg.appendf(" for %s ", tag); + } + SkDebugf("%s\n", msg.c_str()); + #endif } #endif // SK_SUPPORT_GPU diff --git a/src/core/SkGlyphRunPainter.h b/src/core/SkGlyphRunPainter.h index cea4485ce1..23f1972e2e 100644 --- a/src/core/SkGlyphRunPainter.h +++ b/src/core/SkGlyphRunPainter.h @@ -87,7 +87,8 @@ public: const SkMatrix& drawMatrix, const SkPaint& drawPaint, const GrSDFTControl& control, - SkGlyphRunPainterInterface* process); + SkGlyphRunPainterInterface* process, + const char* tag = nullptr); #endif // SK_SUPPORT_GPU private: diff --git a/src/core/SkRemoteGlyphCache.cpp b/src/core/SkRemoteGlyphCache.cpp index c72a091b7e..d76be9d492 100644 --- a/src/core/SkRemoteGlyphCache.cpp +++ b/src/core/SkRemoteGlyphCache.cpp @@ -654,6 +654,10 @@ sk_sp SkStrikeServerImpl::serializeTypeface(SkTypeface* tf) { } void SkStrikeServerImpl::writeStrikeData(std::vector* memory) { + #if defined(SK_TRACE_GLYPH_RUN_PROCESS) + SkString msg; + msg.appendf("\nBegin send strike differences\n"); + #endif size_t strikesToSend = 0; fRemoteStrikesToSend.foreach ([&](RemoteStrike* strike) { if (strike->hasPendingGlyphs()) { @@ -686,6 +690,9 @@ void SkStrikeServerImpl::writeStrikeData(std::vector* memory) { auto it = fDescToRemoteStrike.find(&strike->getDescriptor()); SkASSERT(it != fDescToRemoteStrike.end()); SkASSERT(it->second.get() == strike); + #if defined(SK_TRACE_GLYPH_RUN_PROCESS) + msg.append(strike->getDescriptor().dumpRec()); + #endif } #else @@ -694,10 +701,17 @@ void SkStrikeServerImpl::writeStrikeData(std::vector* memory) { strike->writePendingGlyphs(&serializer); strike->resetScalerContext(); } + #if defined(SK_TRACE_GLYPH_RUN_PROCESS) + msg.append(strike->getDescriptor().dumpRec()); + #endif } #endif ); fRemoteStrikesToSend.reset(); + #if defined(SK_TRACE_GLYPH_RUN_PROCESS) + msg.appendf("End send strike differences"); + SkDebugf("%s\n", msg.c_str()); + #endif } RemoteStrike* SkStrikeServerImpl::getOrCreateCache( @@ -831,7 +845,8 @@ protected: drawMatrix, glyphRunList.paint(), control, - nullptr); + nullptr, + "Cache Diff"); } #endif // SK_SUPPORT_GPU } @@ -994,6 +1009,11 @@ bool SkStrikeClientImpl::readStrikeData(const volatile void* memory, size_t memo addTypeface(wire); } + #if defined(SK_TRACE_GLYPH_RUN_PROCESS) + SkString msg; + msg.appendf("\nBegin receive strike differences\n"); + #endif + if (!deserializer.read(&strikeCount)) READ_FAILURE for (size_t i = 0; i < strikeCount; ++i) { @@ -1002,6 +1022,9 @@ bool SkStrikeClientImpl::readStrikeData(const volatile void* memory, size_t memo SkAutoDescriptor sourceAd; if (!deserializer.readDescriptor(&sourceAd)) READ_FAILURE + #if defined(SK_TRACE_GLYPH_RUN_PROCESS) + msg.appendf(" Received descriptor:\n%s", sourceAd.getDesc()->dumpRec().c_str()); + #endif bool fontMetricsInitialized; if (!deserializer.read(&fontMetricsInitialized)) READ_FAILURE @@ -1023,6 +1046,9 @@ bool SkStrikeClientImpl::readStrikeData(const volatile void* memory, size_t memo SkAutoDescriptor ad; auto* client_desc = auto_descriptor_from_desc(sourceAd.getDesc(), tf->uniqueID(), &ad); + #if defined(SK_TRACE_GLYPH_RUN_PROCESS) + msg.appendf(" Mapped descriptor:\n%s", client_desc->dumpRec().c_str()); + #endif auto strike = fStrikeCache->findStrike(*client_desc); // Metrics are only sent the first time. If the metrics are not initialized, there must // be an existing strike. @@ -1077,6 +1103,11 @@ bool SkStrikeClientImpl::readStrikeData(const volatile void* memory, size_t memo } } +#if defined(SK_TRACE_GLYPH_RUN_PROCESS) + msg.appendf("End receive strike differences"); + SkDebugf("%s\n", msg.c_str()); +#endif + return true; } diff --git a/src/core/SkScalerContext.h b/src/core/SkScalerContext.h index 3a9ecc9668..6b065a490e 100644 --- a/src/core/SkScalerContext.h +++ b/src/core/SkScalerContext.h @@ -128,13 +128,13 @@ public: SkString dump() const { SkString msg; - msg.appendf("Rec\n"); - msg.appendf(" textsize %g prescale %g preskew %g post [%g %g %g %g]\n", + msg.appendf(" Rec\n"); + msg.appendf(" textsize %a prescale %a preskew %a post [%a %a %a %a]\n", fTextSize, fPreScaleX, fPreSkewX, fPost2x2[0][0], fPost2x2[0][1], fPost2x2[1][0], fPost2x2[1][1]); - msg.appendf(" frame %g miter %g format %d join %d cap %d flags %#hx\n", + msg.appendf(" frame %g miter %g format %d join %d cap %d flags %#hx\n", fFrameWidth, fMiterLimit, fMaskFormat, fStrokeJoin, fStrokeCap, fFlags); - msg.appendf(" lum bits %x, device gamma %d, paint gamma %d contrast %d\n", fLumBits, + msg.appendf(" lum bits %x, device gamma %d, paint gamma %d contrast %d\n", fLumBits, fDeviceGamma, fPaintGamma, fContrast); return msg; } diff --git a/src/core/SkStrikeSpec.cpp b/src/core/SkStrikeSpec.cpp index ccaf308415..8ae2e35184 100644 --- a/src/core/SkStrikeSpec.cpp +++ b/src/core/SkStrikeSpec.cpp @@ -140,6 +140,10 @@ bool SkStrikeSpec::ShouldDrawAsPath( || distance(SkMatrix::kMSkewX, SkMatrix::kMScaleY) > maxSizeSquared; } +SkString SkStrikeSpec::dump() const { + return fAutoDescriptor.getDesc()->dumpRec(); +} + SkStrikeSpec SkStrikeSpec::MakePDFVector(const SkTypeface& typeface, int* size) { SkFont font; font.setHinting(SkFontHinting::kNone); diff --git a/src/core/SkStrikeSpec.h b/src/core/SkStrikeSpec.h index 4bc020f265..84ee87c8bd 100644 --- a/src/core/SkStrikeSpec.h +++ b/src/core/SkStrikeSpec.h @@ -89,6 +89,7 @@ public: bool isEmpty() const { return SkScalarNearlyZero(fStrikeToSourceRatio); } const SkDescriptor& descriptor() const { return *fAutoDescriptor.getDesc(); } static bool ShouldDrawAsPath(const SkPaint& paint, const SkFont& font, const SkMatrix& matrix); + SkString dump() const; private: SkStrikeSpec( diff --git a/src/gpu/text/GrTextBlob.cpp b/src/gpu/text/GrTextBlob.cpp index cb54c98615..6e00f09ea1 100644 --- a/src/gpu/text/GrTextBlob.cpp +++ b/src/gpu/text/GrTextBlob.cpp @@ -1506,7 +1506,8 @@ sk_sp GrTextBlob::Make(const SkGlyphRunList& glyphRunList, drawMatrix, glyphRunList.paint(), control, - blob.get()); + blob.get(), + "GrTextBlob"); } return blob;