Browser process pegs CPU at 100% when calling document.cookie |
||||||
Issue description
+cc a few people because Issue 806661 references hangs in GetCookies(), in case this might be related. Starting as RV-G but feel free to open this up.
Chrome Version: 65.0.3325.181
OS: Mac OS X 10.12.6
What steps will reproduce the problem?
(1) Call document.cookie from a webpage
What is the expected result?
Returns whatever document.cookie is supposed to return.
What happens instead?
The JS call hangs for ~5 seconds. The browser process pegs the CPU at 100% during this time. Eventually, the call returns the proper data.
I have a sample of the CPU process, and it looks like we're spending a lot of time under base::ImportantFileWriter::DoScheduledWrite() and net::TransportSecurityPersister::SerializeData().
The most interesting lines appear to be:
2512 Thread_3630868: Chrome_IOThread
+ 2512 thread_start (in libsystem_pthread.dylib) + 13 [0x7fffe44c508d]
+ 2512 _pthread_start (in libsystem_pthread.dylib) + 286 [0x7fffe44c5887]
+ 2512 _pthread_body (in libsystem_pthread.dylib) + 180 [0x7fffe44c593b]
+ 2512 base::(anonymous namespace)::ThreadFunc(void*) (in Google Chrome Framework) load address 0x10b315000 + 0x1e28da7 [platform_thread_posix.cc:77]
+ 2512 base::Thread::ThreadMain() (in Google Chrome Framework) load address 0x10b315000 + 0x1e2d8eb [lock.h:26]
+ 2512 content::BrowserThreadImpl::Run(base::RunLoop*) (in Google Chrome Framework) load address 0x10b315000 + 0x78f234 [browser_thread_impl.cc:292]
+ 2512 content::BrowserThreadImpl::IOThreadRun(base::RunLoop*) (in Google Chrome Framework) load address 0x10b315000 + 0x78f174 [browser_thread_impl.cc:249]
+ 2512 <name omitted> (in Google Chrome Framework) load address 0x10b315000 + 0x1dfc135 [run_loop.cc:136]
+ 2068 base::MessagePumpLibevent::Run(base::MessagePump::Delegate*) (in Google Chrome Framework) load address 0x10b315000 + 0x1dd7cef [message_pump_libevent.cc:231]
+ ! 2068 base::MessageLoop::DoDelayedWork(base::TimeTicks*) (in Google Chrome Framework) load address 0x10b315000 + 0x1dd6ebd [message_loop.cc:411]
+ ! 2068 base::MessageLoop::RunTask(base::PendingTask*) (in Google Chrome Framework) load address 0x10b315000 + 0x1dd6864 [vector:639]
+ ! 2068 base::debug::TaskAnnotator::RunTask(char const*, base::PendingTask*) (in Google Chrome Framework) load address 0x10b315000 + 0x1db1d1c [callback_forward.h:11]
+ ! 2068 base::Timer::RunScheduledTask() (in Google Chrome Framework) load address 0x10b315000 + 0x1e305a7 [callback.h:94]
+ ! 2068 base::ImportantFileWriter::DoScheduledWrite() (in Google Chrome Framework) load address 0x10b315000 + 0x1dc3431 [important_file_writer.cc:269]
+ ! 2068 non-virtual thunk to net::TransportSecurityPersister::SerializeData(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >*) (in Google Chrome Framework) load address 0x10b315000 + 0x2263d9d [transport_security_persister.cc:0]
+ ! 1537 net::TransportSecurityPersister::SerializeData(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >*) (in Google Chrome Framework) load address 0x10b315000 + 0x2263722 [memory:2592]
+ ! : 1537 base::DictionaryValue::Set(base::BasicStringPiece<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> >) (in Google Chrome Framework) load address 0x10b315000 + 0x1e53b35 [flat_map.h:267]
+ ! : 1535 std::__1::pair<std::__1::__wrap_iter<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*>, bool> base::internal::flat_tree<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >, base::internal::GetKeyFromValuePairFirst<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >, std::__1::less<void> >::emplace_key_args<base::BasicStringPiece<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > >, std::__1::piecewise_construct_t const&, std::__1::tuple<base::BasicStringPiece<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > >&>, std::__1::tuple<std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> >&&> >(base::BasicStringPiece<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > > const&, std::__1::piecewise_construct_t const&&&, std::__1::tuple<base::BasicStringPiece<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > >&>&&, std::__1::tuple<std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> >&&>&&) (in Google Chrome Framework) load address 0x10b315000 + 0x1e57c0f [flat_tree.h:949]
+ ! : | 1530 std::__1::__wrap_iter<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*> std::__1::vector<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >, std::__1::allocator<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > > > >::emplace<std::__1::piecewise_construct_t const&, std::__1::tuple<base::BasicStringPiece<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > >&>, std::__1::tuple<std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> >&&> >(std::__1::__wrap_iter<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > > const*>, std::__1::piecewise_construct_t const&&&, std::__1::tuple<base::BasicStringPiece<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > >&>&&, std::__1::tuple<std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> >&&>&&) (in Google Chrome Framework) load address 0x10b315000 + 0x1e58130 [string:1255]
+ ! : | + 729 std::__1::vector<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >, std::__1::allocator<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > > > >::__move_range(std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*, std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*, std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*) (in Google Chrome Framework) load address 0x10b315000 + 0x1e57259 [string:2107]
+ ! : | + ! 729 std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >::reserve(unsigned long) (in libc++.1.dylib) + 13,295,... [0x7fffe2e7af85,0x7fffe2e7b09f,...]
+ ! : | + 153 std::__1::vector<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >, std::__1::allocator<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > > > >::__move_range(std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*, std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*, std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*) (in Google Chrome Framework) load address 0x10b315000 + 0x1e5725e [string:2107]
+ ! : | + 71 std::__1::vector<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >, std::__1::allocator<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > > > >::__move_range(std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*, std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*, std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*) (in Google Chrome Framework) load address 0x10b315000 + 0x1e57267 [string:2107]
+ ! : | + 69 std::__1::vector<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >, std::__1::allocator<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > > > >::__move_range(std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*, std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*, std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*) (in Google Chrome Framework) load address 0x10b315000 + 0x1e5727c [string:1356]
+ ! : | + 66 parseSystemVersionPList (in Google Chrome Framework) + 0 []
+ ! : | + 56 std::__1::vector<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >, std::__1::allocator<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > > > >::__move_range(std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*, std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*, std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*) (in Google Chrome Framework) load address 0x10b315000 + 0x1e57262 [string:2107]
+ ! : | + 48 std::__1::vector<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >, std::__1::allocator<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > > > >::__move_range(std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*, std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*, std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*) (in Google Chrome Framework) load address 0x10b315000 + 0x1e5729a [memory:2592]
+ ! : | + 40 std::__1::vector<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >, std::__1::allocator<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > > > >::__move_range(std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*, std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*, std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::unique_ptr<base::Value, std::__1::default_delete<base::Value> > >*) (in Google Chrome Framework) load address 0x10b315000 + 0x1e5723c [string:1299]
... etc, for another 600 lines
,
Mar 23 2018
The TransportSecurity file in this user's profile is 16MB. As another point of comparison, mine is 85KB.
,
Mar 23 2018
I'm not sure why we'd be mucking with the TransportSecurityPersister when accessing cookies - it has nothing to do with cookies.
,
Mar 23 2018
Could certainly be a coincidence, although the sample does indicate that at least 60% of that thread was spent in net::TransportSecurityPersister::SerializeData() over the sample period, which seems high enough to be a problem by itself? Getting more details about the repro case: "Website is calling document.cookie in a timer every 5 seconds. About every 30 seconds, that call hangs for ~5 seconds. Everything in the page is unresponsive, and there are zero frames rendered. While this is happening, the browser pegs the CPU for the whole time." Is it possible that the cookies fetch and the TransportSecurityPersister are getting scheduled on the same TaskRunner, and a long-running operation is blocking the cookies fetch from running? That might also explain why it only happens on some of the fetches but not all. Does the TransportSecurityPersister happen to flush to disk on a 30 second timer?
,
Mar 24 2018
-RVG so the original reporter can contribute.
,
Mar 26 2018
,
Mar 26 2018
I don't think the TransportSecurityPersister writes to disk on a regular schedule (?). AFAICT it should only serialize/write when the state is updated or on startup. Is this bug reproducing on a particular website or on all websites? Maybe the website is doing something weird like constantly modifying the HSTS state...
,
Mar 26 2018
I've asked the original reporter to chime in. I know that they were doing something wonky that has probably ended up causing a ton of HSTS entries in the database. (It's hard to tell because the entries are hashed, but they were going to try and test some of the hashes to confirm this theory.) That aside, I think there are also other issues in that: 1) Having a large HSTS database shouldn't affect the performance of document.cookies. The samples I have strongly imply that the CPU was pegged in TransportSecurityPersister, and the original reporter indicated that the samples were taken while document.cookies was unresponsive. 2) Even if you have a large HSTS database, we should be able to flush it to disk in a reasonable amount of time? Or maybe we should have protection against it growing too large in size?
,
Mar 26 2018
getcookies is sync so possibly just flooding the IPC thread on browser with whatever is happening in HSTS state, might result in this taking some time to fulfil..?
,
Oct 17
|
||||||
►
Sign in to add a comment |
||||||
Comment 1 by roc...@chromium.org
, Mar 23 2018