Project: chromium Issues People Development process History Sign in
New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.
Issue 90127 FontCache::PreCacheFont() is janky on Windows
Starred by 4 users Project Member Reported by, Jul 22 2011 Back to list
Status: Assigned
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 3
Type: Bug

Sign in to add a comment
Wondering if PreCacheFont (which calls getTextMetrics) be accessing the disk on IO thread? If so, could we do it on File Thread?

IO thread was not responding for 12 secs when we were caching fonts.

thanks much,

Product: Chrome
Stack Signature: base::debug::BreakDebugger()-3A4CCF
New Signature Label: base::debug::BreakDebugger()
New Signature Hash: 2e887951_f7fbac59_08a08644_fe3d52be_d9c1ec8c

Report link: http://go/crash/reportdetail?reportid=9f43089207d53382

Meta information:
Product Name: Chrome
Product Version: 13.0.782.55
Report ID: 9f43089207d53382
Report Time: 2011/07/18 13:57:57, Mon
Uptime: 232 sec
Cumulative Uptime: 0 sec
OS Name: Windows NT
OS Version: 5.1.2600 Service Pack 3
CPU Architecture: x86
CPU Info: GenuineIntel family 6 model 14 stepping 8

The callstack of IO thread

Thread 10

0x7c90e514	 [ntdll.dll	 + 0x0000e514]	KiFastSystemCallRet
0x77f1a59d	 [gdi32.dll	 + 0x0000a59d]	NtGdiGetTextMetricsW
0x77f17e30	 [gdi32.dll	 + 0x00007e30]	GetTextMetricsW
0x0268c946	 [chrome.dll	 -	ChildProcessHost::PreCacheFont(tagLOGFONTW)
0x026c8bf2	 [chrome.dll	 -	RenderMessageFilter::OnPreCacheFont(tagLOGFONTW)
0x026c97ce	 [chrome.dll	 - ipc_message_utils.h:1170	IPC::MessageWithReply<Tuple1<tagLOGFONTW>,Tuple0>::Dispatch<RenderMessageFilter,RenderMessageFilter,void ( RenderMessageFilter::*)(tagLOGFONTW)>(IPC::Message const *,RenderMessageFilter *,RenderMessageFilter *,void ( RenderMessageFilter::*)(tagLOGFONTW))
0x026c868a	 [chrome.dll	 -	RenderMessageFilter::OnMessageReceived(IPC::Message const &,bool *)
0x026be0a1	 [chrome.dll	 -	BrowserMessageFilter::DispatchMessageW(IPC::Message const &)
0x026be01d	 [chrome.dll	 -	BrowserMessageFilter::OnMessageReceived(IPC::Message const &)
0x020defd1	 [chrome.dll	 -	IPC::ChannelProxy::Context::TryFilters(IPC::Message const &)
0x020e0b4f	 [chrome.dll	 -	IPC::SyncChannel::SyncContext::OnMessageReceived(IPC::Message const &)
0x020e24f5	 [chrome.dll	 -	IPC::Channel::ChannelImpl::ProcessIncomingMessages(base::MessagePumpForIO::IOContext *,unsigned long)
0x020e27af	 [chrome.dll	 -	IPC::Channel::ChannelImpl::OnIOCompleted(base::MessagePumpForIO::IOContext *,unsigned long,unsigned long)
0x01c53f31	 [chrome.dll	 -	base::MessagePumpForIO::WaitForIOCompletion(unsigned long,base::MessagePumpForIO::IOHandler *)
0x01c53e4a	 [chrome.dll	 -	base::MessagePumpForIO::DoRunLoop()
0x01c53887	 [chrome.dll	 -	base::MessagePumpWin::RunWithDispatcher(base::MessagePump::Delegate *,base::MessagePumpWin::Dispatcher *)
0x01c5379b	 [chrome.dll	 - message_pump_win.h:80	base::MessagePumpWin::Run(base::MessagePump::Delegate *)
0x01c45a6d	 [chrome.dll	 -	MessageLoop::RunInternal()
0x01c459f2	 [chrome.dll	 -	MessageLoop::RunHandler()
0x01c458e6	 [chrome.dll	 -	MessageLoop::Run()
0x0208cb84	 [chrome.dll	 -	base::Thread::Run(MessageLoop *)
0x0208cc97	 [chrome.dll	 -	base::Thread::ThreadMain()
0x01c5413e	 [chrome.dll	 -	base::`anonymous namespace'::ThreadFunc(void *)
0x7c80b728	 [kernel32.dll	 + 0x0000b728]	BaseThreadStart

This happens on Windows XP. If it is a single core slow machine, it is possible IO thread is not getting enough time to respond to ping messages.


Thread 9

0x7c90e514	 [ntdll.dll	 + 0x0000e514]	KiFastSystemCallRet
0x77f1a59d	 [gdi32.dll	 + 0x0000a59d]	NtGdiGetTextMetricsW
0x77f17e30	 [gdi32.dll	 + 0x00007e30]	GetTextMetricsW
0x027ac145	 [chrome.dll	 -	ChildProcessHost::PreCacheFont(tagLOGFONTW)
0x01e71456	 [chrome.dll	 -	RenderMessageFilter::OnPreCacheFont(tagLOGFONTW const &)
0x022d4564	 [chrome.dll	 - ipc_message_utils.h:1171	IPC::MessageWithReply<Tuple1<tagLOGFONTW>,Tuple0>::Dispatch<RenderMessageFilter,RenderMessageFilter,void ( RenderMessageFilter::*)(tagLOGFONTW const &)>(IPC::Message const *,RenderMessageFilter *,RenderMessageFilter *,void ( RenderMessageFilter::*)(tagLOGFONTW const &))
0x022d31e5	 [chrome.dll	 -	RenderMessageFilter::OnMessageReceived(IPC::Message const &,bool *)
0x022bf2aa	 [chrome.dll	 -	BrowserMessageFilter::DispatchMessageW(IPC::Message const &)
0x022bf226	 [chrome.dll	 -	BrowserMessageFilter::OnMessageReceived(IPC::Message const &)
0x01d1046a	 [chrome.dll	 -	IPC::ChannelProxy::Context::TryFilters(IPC::Message const &)
0x01d10495	 [chrome.dll	 -	IPC::ChannelProxy::Context::OnMessageReceived(IPC::Message const &)
0x01d0f545	 [chrome.dll	 -	IPC::Channel::ChannelImpl::ProcessIncomingMessages(base::MessagePumpForIO::IOContext *,unsigned long)
0x01d0f7ff	 [chrome.dll	 -	IPC::Channel::ChannelImpl::OnIOCompleted(base::MessagePumpForIO::IOContext *,unsigned long,unsigned long)
0x01e5bf9c	 [chrome.dll	 -	base::MessagePumpForIO::WaitForIOCompletion(unsigned long,base::MessagePumpForIO::IOHandler *)
0x01e5be67	 [chrome.dll	 -	base::MessagePumpForIO::DoRunLoop()
0x01e5b8f2	 [chrome.dll	 -	base::MessagePumpWin::RunWithDispatcher(base::MessagePump::Delegate *,base::MessagePumpWin::Dispatcher *)
0x01e5b806	 [chrome.dll	 - message_pump_win.h:80	base::MessagePumpWin::Run(base::MessagePump::Delegate *)
0x01e42b88	 [chrome.dll	 -	MessageLoop::RunInternal()
0x01e42b0d	 [chrome.dll	 -	MessageLoop::RunHandler()
0x01e42a72	 [chrome.dll	 -	MessageLoop::Run()
0x01e52d71	 [chrome.dll	 -	base::Thread::Run(MessageLoop *)
0x01e52e84	 [chrome.dll	 -	base::Thread::ThreadMain()
0x01e476e6	 [chrome.dll	 -	base::`anonymous namespace'::ThreadFunc(void *)
0x7c80b728	 [kernel32.dll	 + 0x0000b728]	BaseThreadStart

This happened few times in M14 (beta)


The following is from M15 dev (15.0.849.0)


The following is from M15 canary (15.0.859.0)


Is this a Win XP specific problem or could ChildProcessHost::PreCacheFont be taking too long and should we perform this task on a different thread?
Comment 2 by, Aug 25 2011
To prevent this from regressing, we should add a ThreadRestrictions::AssertIOAllowed() right before the call to GetTextMetrics.
Comment 3 by, Sep 2 2011
Labels: -Pri-2 Pri-1 TaskForce-Jank
Status: Assigned
Comment 4 by, Sep 8 2011
Labels: Stability-CodeYellow
Project Member Comment 5 by, Mar 10 2013
Labels: -Area-Internals -Feature-Fonts Cr-Internals Cr-Content-Fonts
Project Member Comment 6 by, Apr 6 2013
Labels: Cr-Blink
Project Member Comment 7 by, Apr 6 2013
Labels: -Cr-Content-Fonts Cr-Blink-Fonts
Labels: -Pri-1 -TaskForce-Jank -Stability-CodeYellow -Cr-Blink Pri-3 Hotlist-Slow M-44
Summary: FontCache::PreCacheFont() is janky on Windows (was: could ChildProcessHost::PreCacheFont be blocking IO thread for more than 12 secs)
The jank dashboard suggests that PreCacheFont() is janky on Windows at ~1 JPH.

I don't know whether this code is still necessary (given how many changes to font rendering we've had in the years since this was filed) or who the best owner is; assigning to ananta in hopes he can triage further.

I'll add a ScopedTracker to track the jank of this function.
Labels: -M-44 MovedFrom-44 M-45
[AUTO] Moving all non essential bugs to the next Milestone.  (This decision is based on the labels attached to your ticket.)

Comment 12 by, Mar 29 2016
Components: -Blink>Fonts
Sign in to add a comment