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 rtenneti@chromium.org, Jul 22 2011 Back to list
Status: Assigned
Owner:
Cc:
Components:
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,
raman


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	 - child_process_host.cc:96	ChildProcessHost::PreCacheFont(tagLOGFONTW)
0x026c8bf2	 [chrome.dll	 - render_message_filter.cc:526	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	 - render_message_filter.cc:332	RenderMessageFilter::OnMessageReceived(IPC::Message const &,bool *)
0x026be0a1	 [chrome.dll	 - browser_message_filter.cc:83	BrowserMessageFilter::DispatchMessageW(IPC::Message const &)
0x026be01d	 [chrome.dll	 - browser_message_filter.cc:69	BrowserMessageFilter::OnMessageReceived(IPC::Message const &)
0x020defd1	 [chrome.dll	 - ipc_channel_proxy.cc:88	IPC::ChannelProxy::Context::TryFilters(IPC::Message const &)
0x020e0b4f	 [chrome.dll	 - ipc_sync_channel.cc:304	IPC::SyncChannel::SyncContext::OnMessageReceived(IPC::Message const &)
0x020e24f5	 [chrome.dll	 - ipc_channel_win.cc:284	IPC::Channel::ChannelImpl::ProcessIncomingMessages(base::MessagePumpForIO::IOContext *,unsigned long)
0x020e27af	 [chrome.dll	 - ipc_channel_win.cc:375	IPC::Channel::ChannelImpl::OnIOCompleted(base::MessagePumpForIO::IOContext *,unsigned long,unsigned long)
0x01c53f31	 [chrome.dll	 - message_pump_win.cc:514	base::MessagePumpForIO::WaitForIOCompletion(unsigned long,base::MessagePumpForIO::IOHandler *)
0x01c53e4a	 [chrome.dll	 - message_pump_win.cc:477	base::MessagePumpForIO::DoRunLoop()
0x01c53887	 [chrome.dll	 - message_pump_win.cc:51	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	 - message_loop.cc:449	MessageLoop::RunInternal()
0x01c459f2	 [chrome.dll	 - message_loop.cc:422	MessageLoop::RunHandler()
0x01c458e6	 [chrome.dll	 - message_loop.cc:346	MessageLoop::Run()
0x0208cb84	 [chrome.dll	 - thread.cc:128	base::Thread::Run(MessageLoop *)
0x0208cc97	 [chrome.dll	 - thread.cc:164	base::Thread::ThreadMain()
0x01c5413e	 [chrome.dll	 - platform_thread_win.cc:37	base::`anonymous namespace'::ThreadFunc(void *)
0x7c80b728	 [kernel32.dll	 + 0x0000b728]	BaseThreadStart


 
Cc: jhawkins@chromium.org
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.

http://crash/reportdetail?reportid=ba0ea41d953ec84e

Thread 9

0x7c90e514	 [ntdll.dll	 + 0x0000e514]	KiFastSystemCallRet
0x77f1a59d	 [gdi32.dll	 + 0x0000a59d]	NtGdiGetTextMetricsW
0x77f17e30	 [gdi32.dll	 + 0x00007e30]	GetTextMetricsW
0x027ac145	 [chrome.dll	 - child_process_host.cc:96	ChildProcessHost::PreCacheFont(tagLOGFONTW)
0x01e71456	 [chrome.dll	 - service_utility_process_host.cc:161	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	 - render_message_filter.cc:324	RenderMessageFilter::OnMessageReceived(IPC::Message const &,bool *)
0x022bf2aa	 [chrome.dll	 - browser_message_filter.cc:83	BrowserMessageFilter::DispatchMessageW(IPC::Message const &)
0x022bf226	 [chrome.dll	 - browser_message_filter.cc:69	BrowserMessageFilter::OnMessageReceived(IPC::Message const &)
0x01d1046a	 [chrome.dll	 - ipc_channel_proxy.cc:88	IPC::ChannelProxy::Context::TryFilters(IPC::Message const &)
0x01d10495	 [chrome.dll	 - ipc_channel_proxy.cc:102	IPC::ChannelProxy::Context::OnMessageReceived(IPC::Message const &)
0x01d0f545	 [chrome.dll	 - ipc_channel_win.cc:284	IPC::Channel::ChannelImpl::ProcessIncomingMessages(base::MessagePumpForIO::IOContext *,unsigned long)
0x01d0f7ff	 [chrome.dll	 - ipc_channel_win.cc:375	IPC::Channel::ChannelImpl::OnIOCompleted(base::MessagePumpForIO::IOContext *,unsigned long,unsigned long)
0x01e5bf9c	 [chrome.dll	 - message_pump_win.cc:514	base::MessagePumpForIO::WaitForIOCompletion(unsigned long,base::MessagePumpForIO::IOHandler *)
0x01e5be67	 [chrome.dll	 - message_pump_win.cc:458	base::MessagePumpForIO::DoRunLoop()
0x01e5b8f2	 [chrome.dll	 - message_pump_win.cc:51	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	 - message_loop.cc:451	MessageLoop::RunInternal()
0x01e42b0d	 [chrome.dll	 - message_loop.cc:424	MessageLoop::RunHandler()
0x01e42a72	 [chrome.dll	 - message_loop.cc:348	MessageLoop::Run()
0x01e52d71	 [chrome.dll	 - thread.cc:128	base::Thread::Run(MessageLoop *)
0x01e52e84	 [chrome.dll	 - thread.cc:164	base::Thread::ThreadMain()
0x01e476e6	 [chrome.dll	 - platform_thread_win.cc:37	base::`anonymous namespace'::ThreadFunc(void *)
0x7c80b728	 [kernel32.dll	 + 0x0000b728]	BaseThreadStart

This happened few times in M14 (beta)

http://crash/reportdetail?reportid=12683c3b2826335b
http://crash/reportdetail?reportid=5f580e3e19acc3cc
http://crash/reportdetail?reportid=2c427a423b6a49ea
http://crash/reportdetail?reportid=ec10cffab0266dd5

The following is from M15 dev (15.0.849.0)

http://crash/reportdetail?reportid=7dee4af3d327b9ee

The following is from M15 canary (15.0.859.0)

http://crash/reportdetail?reportid=f670e00b6deebad9

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 evan@chromium.org, Aug 25 2011
To prevent this from regressing, we should add a ThreadRestrictions::AssertIOAllowed() right before the call to GetTextMetrics.
Comment 3 by k...@google.com, Sep 2 2011
Labels: -Pri-2 Pri-1 TaskForce-Jank
Owner: mikelawther@chromium.org
Status: Assigned
Comment 4 by mal@google.com, Sep 8 2011
Labels: Stability-CodeYellow
Project Member Comment 5 by bugdroid1@chromium.org, Mar 10 2013
Labels: -Area-Internals -Feature-Fonts Cr-Internals Cr-Content-Fonts
Project Member Comment 6 by bugdroid1@chromium.org, Apr 6 2013
Labels: Cr-Blink
Project Member Comment 7 by bugdroid1@chromium.org, Apr 6 2013
Labels: -Cr-Content-Fonts Cr-Blink-Fonts
Cc: msw@chromium.org ckocagil@chromium.org mikelawther@chromium.org
Labels: -Pri-1 -TaskForce-Jank -Stability-CodeYellow -Cr-Blink Pri-3 Hotlist-Slow M-44
Owner: ananta@chromium.org
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.)


Ref: https://sites.google.com/a/chromium.org/dev/developers/ticket-milestone-punting-1
Cc: -willchan@chromium.org
Comment 12 by e...@chromium.org, Mar 29 2016
Components: -Blink>Fonts
Cc: -jhawkins@chromium.org
Sign in to add a comment