Skip to content

Commit

Permalink
Bug 602792. Clean up font logs and add system fallback logging. r=bas…
Browse files Browse the repository at this point in the history 
…, a=blocker
  • Loading branch information
John Daggett committed Jan 21, 2011
1 parent a1b4779 commit eeb92a1
Show file tree
Hide file tree
Showing 11 changed files with 337 additions and 130 deletions.
8 changes: 0 additions & 8 deletions gfx/thebes/gfxCoreTextShaper.cpp
View file
Expand Up @@ -62,14 +62,6 @@

#include "nsUnicodeRange.h"

// Uncomment this to dump all text runs created to the log (if enabled)
//#define DUMP_TEXT_RUNS

#ifdef DUMP_TEXT_RUNS
static PRLogModuleInfo *gCoreTextTextRunLog = PR_NewLogModule("coreTextTextRun");
#endif


// standard font descriptors that we construct the first time they're needed
CTFontDescriptorRef gfxCoreTextShaper::sDefaultFeaturesDescriptor = NULL;
CTFontDescriptorRef gfxCoreTextShaper::sDisableLigaturesDescriptor = NULL;
Expand Down
69 changes: 48 additions & 21 deletions gfx/thebes/gfxDWriteFontList.cpp
View file
Expand Up @@ -51,10 +51,20 @@
#include "nsIWindowsRegKey.h"

#ifdef PR_LOGGING
static PRLogModuleInfo *gFontInitLog = nsnull;
#define LOG(args) PR_LOG(gFontInitLog, PR_LOG_DEBUG, args)
#define LOG_ENABLED() (gFontInitLog) && PR_LOG_TEST(gFontInitLog, PR_LOG_DEBUG)
#endif /* PR_LOGGING */

#define LOG_FONTLIST(args) PR_LOG(gfxPlatform::GetLog(eGfxLog_fontlist), \
PR_LOG_DEBUG, args)
#define LOG_FONTLIST_ENABLED() PR_LOG_TEST( \
gfxPlatform::GetLog(eGfxLog_fontlist), \
PR_LOG_DEBUG)

#define LOG_FONTINIT(args) PR_LOG(gfxPlatform::GetLog(eGfxLog_fontinit), \
PR_LOG_DEBUG, args)
#define LOG_FONTINIT_ENABLED() PR_LOG_TEST( \
gfxPlatform::GetLog(eGfxLog_fontinit), \
PR_LOG_DEBUG)

#endif // PR_LOGGING

// font info loader constants

Expand Down Expand Up @@ -135,6 +145,7 @@ gfxDWriteFontFamily::FindStyleVariations()
}

nsString fullID(mName);
fullID.Append(NS_LITERAL_STRING(" "));
fullID.Append(faceName.Elements());

/**
Expand All @@ -145,6 +156,17 @@ gfxDWriteFontFamily::FindStyleVariations()
new gfxDWriteFontEntry(fullID, font);
fe->SetFamily(this);

#ifdef PR_LOGGING
if (LOG_FONTLIST_ENABLED()) {
LOG_FONTLIST(("(fontlist) added (%s) to family (%s)"
" with style: %s weight: %d stretch: %d",
NS_ConvertUTF16toUTF8(fe->Name()).get(),
NS_ConvertUTF16toUTF8(Name()).get(),
(fe->IsItalic()) ? "italic" : "normal",
fe->Weight(), fe->Stretch()));
}
#endif

mAvailableFonts.AppendElement(fe);
}
if (!mAvailableFonts.Length()) {
Expand Down Expand Up @@ -360,6 +382,11 @@ gfxDWriteFontEntry::ReadCMAP()
}
fontFace->ReleaseFontTable(tableContext);

#ifdef PR_LOGGING
LOG_FONTLIST(("(fontlist-cmap) name: %s, size: %d\n",
NS_ConvertUTF16toUTF8(mName).get(), mCharacterMap.GetSize()));
#endif

mHasCmapTable = NS_SUCCEEDED(rv);
return rv;
}
Expand Down Expand Up @@ -558,14 +585,12 @@ gfxDWriteFontList::InitFontList()
{

#ifdef PR_LOGGING
gFontInitLog = PR_NewLogModule("fontinit");

LARGE_INTEGER frequency; // ticks per second
LARGE_INTEGER t1, t2, t3, t4, t5, t6; // ticks
double elapsedTime, upTime;
char nowTime[256], nowDate[256];

if (LOG_ENABLED()) {
if (LOG_FONTINIT_ENABLED()) {
GetTimeFormat(LOCALE_INVARIANT, TIME_FORCE24HOURFORMAT,
NULL, NULL, nowTime, 256);
GetDateFormat(LOCALE_INVARIANT, NULL, NULL, NULL, nowDate, 256);
Expand Down Expand Up @@ -597,7 +622,7 @@ gfxDWriteFontList::InitFontList()
mNonExistingFonts.Clear();

#ifdef PR_LOGGING
if (LOG_ENABLED()) {
if (LOG_FONTINIT_ENABLED()) {
QueryPerformanceCounter(&t2);
}
#endif
Expand All @@ -612,7 +637,7 @@ gfxDWriteFontList::InitFontList()
}

#ifdef PR_LOGGING
if (LOG_ENABLED()) {
if (LOG_FONTINIT_ENABLED()) {
QueryPerformanceCounter(&t3);
}
#endif
Expand All @@ -624,7 +649,7 @@ gfxDWriteFontList::InitFontList()
}

#ifdef PR_LOGGING
if (LOG_ENABLED()) {
if (LOG_FONTINIT_ENABLED()) {
QueryPerformanceCounter(&t4);
}
#endif
Expand Down Expand Up @@ -736,29 +761,31 @@ gfxDWriteFontList::InitFontList()
StartLoader(kDelayBeforeLoadingFonts, kIntervalBetweenLoadingFonts);

#ifdef PR_LOGGING
if (LOG_ENABLED()) {
if (LOG_FONTINIT_ENABLED()) {
QueryPerformanceCounter(&t5);

// determine dwrite version
nsAutoString dwriteVers;
gfxWindowsPlatform::GetPlatform()->GetDLLVersion(L"dwrite.dll",
dwriteVers);
LOG(("InitFontList\n"));
LOG(("Start: %s %s\n", nowDate, nowTime));
LOG(("Uptime: %9.3f s\n", upTime/1000));
LOG(("dwrite version: %s\n", NS_ConvertUTF16toUTF8(dwriteVers).get()));
LOG_FONTINIT(("InitFontList\n"));
LOG_FONTINIT(("Start: %s %s\n", nowDate, nowTime));
LOG_FONTINIT(("Uptime: %9.3f s\n", upTime/1000));
LOG_FONTINIT(("dwrite version: %s\n",
NS_ConvertUTF16toUTF8(dwriteVers).get()));
elapsedTime = (t5.QuadPart - t1.QuadPart) * 1000.0 / frequency.QuadPart;
LOG(("Total time in InitFontList: %9.3f ms (families: %d, %s)\n",
elapsedTime, systemFonts->GetFontFamilyCount(),
LOG_FONTINIT((
"Total time in InitFontList: %9.3f ms (families: %d, %s)\n",
elapsedTime, systemFonts->GetFontFamilyCount(),
(mGDIFontTableAccess ? "gdi table access" : "dwrite table access")));
elapsedTime = (t2.QuadPart - t1.QuadPart) * 1000.0 / frequency.QuadPart;
LOG((" --- gfxPlatformFontList init: %9.3f ms\n", elapsedTime));
LOG_FONTINIT((" --- gfxPlatformFontList init: %9.3f ms\n", elapsedTime));
elapsedTime = (t3.QuadPart - t2.QuadPart) * 1000.0 / frequency.QuadPart;
LOG((" --- GetSystemFontCollection: %9.3f ms\n", elapsedTime));
LOG_FONTINIT((" --- GetSystemFontCollection: %9.3f ms\n", elapsedTime));
elapsedTime = (t4.QuadPart - t3.QuadPart) * 1000.0 / frequency.QuadPart;
LOG((" --- GdiInterop object: %9.3f ms\n", elapsedTime));
LOG_FONTINIT((" --- GdiInterop object: %9.3f ms\n", elapsedTime));
elapsedTime = (t5.QuadPart - t4.QuadPart) * 1000.0 / frequency.QuadPart;
LOG((" --- iterate over families: %9.3f ms\n", elapsedTime));
LOG_FONTINIT((" --- iterate over families: %9.3f ms\n", elapsedTime));
}
#endif

Expand Down
94 changes: 66 additions & 28 deletions gfx/thebes/gfxFont.cpp
View file
Expand Up @@ -38,6 +38,11 @@
*
* ***** END LICENSE BLOCK ***** */

#ifdef MOZ_LOGGING
#define FORCE_PR_LOG /* Allow logging in the release build */
#endif
#include "prlog.h"

#include "nsIPrefService.h"
#include "nsServiceManagerUtils.h"
#include "nsReadableUtils.h"
Expand Down Expand Up @@ -72,8 +77,6 @@ using namespace mozilla;

gfxFontCache *gfxFontCache::gGlobalCache = nsnull;

static PRLogModuleInfo *gFontSelection = PR_NewLogModule("fontSelectionLog");

#ifdef DEBUG_roc
#define DEBUG_TEXT_RUN_STORAGE_METRICS
#endif
Expand Down Expand Up @@ -466,11 +469,6 @@ gfxFontFamily::FindFontForStyle(const gfxFontStyle& aFontStyle,
// check remaining faces in order of preference to find the first that actually exists
fe = mAvailableFonts[order[trial]];
if (fe) {
PR_LOG(gFontSelection, PR_LOG_DEBUG,
("(FindFontForStyle) name: %s, sty: %02x, wt: %d, sz: %.1f -> %s (trial %d)\n",
NS_ConvertUTF16toUTF8(mName).get(),
aFontStyle.style, aFontStyle.weight, aFontStyle.size,
NS_ConvertUTF16toUTF8(fe->Name()).get(), trial));
aNeedsSyntheticBold = wantBold && !fe->IsBold();
return fe;
}
Expand All @@ -489,10 +487,6 @@ gfxFontFamily::FindFontForStyle(const gfxFontStyle& aFontStyle,
gfxFontEntry *weightList[10] = { 0 };
PRBool foundWeights = FindWeightsForStyle(weightList, wantItalic, aFontStyle.stretch);
if (!foundWeights) {
PR_LOG(gFontSelection, PR_LOG_DEBUG,
("(FindFontForStyle) name: %s, sty: %02x, wt: %d, sz: %.1f -> null\n",
NS_ConvertUTF16toUTF8(mName).get(),
aFontStyle.style, aFontStyle.weight, aFontStyle.size));
return nsnull;
}

Expand Down Expand Up @@ -535,11 +529,6 @@ gfxFontFamily::FindFontForStyle(const gfxFontStyle& aFontStyle,
aNeedsSyntheticBold = PR_TRUE;
}

PR_LOG(gFontSelection, PR_LOG_DEBUG,
("(FindFontForStyle) name: %s, sty: %02x, wt: %d, sz: %.1f -> %s\n",
NS_ConvertUTF16toUTF8(mName).get(),
aFontStyle.style, aFontStyle.weight, aFontStyle.size,
NS_ConvertUTF16toUTF8(matchFE->Name()).get()));
return matchFE;
}

Expand Down Expand Up @@ -677,6 +666,22 @@ gfxFontFamily::FindFontForChar(FontSearch *aMatchData)

if (fe->TestCharacterMap(aMatchData->mCh)) {
rank += 20;
aMatchData->mCount++;
#ifdef PR_LOGGING
PRLogModuleInfo *log = gfxPlatform::GetLog(eGfxLog_textrun);

if (NS_UNLIKELY(log)) {
PRUint32 charRange = gfxFontUtils::CharRangeBit(aMatchData->mCh);
PRUint32 unicodeRange = FindCharUnicodeRange(aMatchData->mCh);
PRUint32 hbscript = gfxUnicodeProperties::GetScriptCode(aMatchData->mCh);
PR_LOG(log, PR_LOG_DEBUG,\
("(textrun-systemfallback-fonts) char: u+%6.6x "
"char-range: %d unicode-range: %d script: %d match: [%s]\n",
aMatchData->mCh,
charRange, unicodeRange, hbscript,
NS_ConvertUTF16toUTF8(fe->Name()).get()));
}
#endif
}

// if we didn't match any characters don't bother wasting more time with this face.
Expand Down Expand Up @@ -1444,6 +1449,24 @@ gfxFont::SplitAndInitTextRun(gfxContext *aContext,
{
PRBool ok;

#ifdef PR_LOGGING
PRLogModuleInfo *log = (mStyle.systemFont ?
gfxPlatform::GetLog(eGfxLog_textrunui) :
gfxPlatform::GetLog(eGfxLog_textrun));

if (NS_UNLIKELY(log)) {
nsCAutoString lang;
mStyle.language->ToUTF8String(lang);
PR_LOG(log, PR_LOG_DEBUG,\
("(%s-fontmatching) font: [%s] lang: %s script: %d len: %d "
"TEXTRUN [%s] ENDTEXTRUN\n",
(mStyle.systemFont ? "textrunui" : "textrun"),
NS_ConvertUTF16toUTF8(GetName()).get(),
lang.get(), aRunScript, aRunLength,
NS_ConvertUTF16toUTF8(aString + aRunStart, aRunLength).get()));
}
#endif

do {
// Because various shaping backends struggle with very long runs,
// we look for appropriate break locations (preferring whitespace),
Expand Down Expand Up @@ -2385,9 +2408,36 @@ gfxFontGroup::InitTextRun(gfxContext *aContext,
// the font matching process below
gfxScriptItemizer scriptRuns(aString, aLength);

#ifdef PR_LOGGING
PRLogModuleInfo *log = (mStyle.systemFont ?
gfxPlatform::GetLog(eGfxLog_textrunui) :
gfxPlatform::GetLog(eGfxLog_textrun));
#endif

PRUint32 runStart = 0, runLimit = aLength;
PRInt32 runScript = HB_SCRIPT_LATIN;
while (scriptRuns.Next(runStart, runLimit, runScript)) {

#ifdef PR_LOGGING
if (NS_UNLIKELY(log)) {
nsCAutoString lang;
mStyle.language->ToUTF8String(lang);
PRUint32 runLen = runLimit - runStart;
PR_LOG(log, PR_LOG_DEBUG,\
("(%s) fontgroup: [%s] lang: %s script: %d len %d "
"weight: %d width: %d style: %s "
"TEXTRUN [%s] ENDTEXTRUN\n",
(mStyle.systemFont ? "textrunui" : "textrun"),
NS_ConvertUTF16toUTF8(mFamilies).get(),
lang.get(), runScript, runLen,
PRUint32(mStyle.weight), PRUint32(mStyle.stretch),
(mStyle.style & FONT_STYLE_ITALIC ? "italic" :
(mStyle.style & FONT_STYLE_OBLIQUE ? "oblique" :
"normal")),
NS_ConvertUTF16toUTF8(aString + runStart, runLen).get()));
}
#endif

InitScriptRun(aContext, aTextRun, aString, aLength,
runStart, runLimit, runScript);
}
Expand Down Expand Up @@ -2454,18 +2504,6 @@ gfxFontGroup::InitScriptRun(gfxContext *aContext,
// ligatures" with the wrong font.
aTextRun->SanitizeGlyphRuns();

#ifdef DUMP_TEXT_RUNS
nsCAutoString lang;
style->language->ToUTF8String(lang);
PR_LOG(gFontSelection, PR_LOG_DEBUG,\
("InitTextRun %p fontgroup %p (%s) lang: %s len %d features: %s "
"TEXTRUN \"%s\" ENDTEXTRUN\n",
aTextRun, this,
NS_ConvertUTF16toUTF8(mFamilies).get(),
lang.get(), aLength,
NS_ConvertUTF16toUTF8(mStyle.featureSettings).get(),
NS_ConvertUTF16toUTF8(aString, aLength).get()) );
#endif
}


Expand Down
3 changes: 2 additions & 1 deletion gfx/thebes/gfxFont.h
View file
Expand Up @@ -460,12 +460,13 @@ class gfxFontEntry {
// used when picking fallback font
struct FontSearch {
FontSearch(const PRUint32 aCharacter, gfxFont *aFont) :
mCh(aCharacter), mFontToMatch(aFont), mMatchRank(0) {
mCh(aCharacter), mFontToMatch(aFont), mMatchRank(0), mCount(0) {
}
const PRUint32 mCh;
gfxFont* mFontToMatch;
PRInt32 mMatchRank;
nsRefPtr<gfxFontEntry> mBestMatch;
PRUint32 mCount;
};

class gfxFontFamily {
Expand Down

0 comments on commit eeb92a1

Please sign in to comment.