{"action":"opened","issue":{"url":"https://api.github.com/repos/dart-lang/sdk/issues/25271","labels_url":"https://api.github.com/repos/dart-lang/sdk/issues/25271/labels{/name}","comments_url":"https://api.github.com/repos/dart-lang/sdk/issues/25271/comments","events_url":"https://api.github.com/repos/dart-lang/sdk/issues/25271/events","html_url":"https://github.com/dart-lang/sdk/issues/25271","id":122403784,"number":25271,"title":"Strong mode can be extremely slow on some large projects","user":{"login":"leafpetersen","id":8484504,"avatar_url":"https://avatars.githubusercontent.com/u/8484504?v=3","gravatar_id":"","url":"https://api.github.com/users/leafpetersen","html_url":"https://github.com/leafpetersen","followers_url":"https://api.github.com/users/leafpetersen/followers","following_url":"https://api.github.com/users/leafpetersen/following{/other_user}","gists_url":"https://api.github.com/users/leafpetersen/gists{/gist_id}","starred_url":"https://api.github.com/users/leafpetersen/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/leafpetersen/subscriptions","organizations_url":"https://api.github.com/users/leafpetersen/orgs","repos_url":"https://api.github.com/users/leafpetersen/repos","events_url":"https://api.github.com/users/leafpetersen/events{/privacy}","received_events_url":"https://api.github.com/users/leafpetersen/received_events","type":"User","site_admin":false},"labels":[{"url":"https://api.github.com/repos/dart-lang/sdk/labels/analyzer-strong-mode","name":"analyzer-strong-mode","color":"d4c5f9"},{"url":"https://api.github.com/repos/dart-lang/sdk/labels/area-analyzer","name":"area-analyzer","color":"c7def8"},{"url":"https://api.github.com/repos/dart-lang/sdk/labels/priority-high","name":"priority-high","color":"eb6420"}],"state":"open","locked":false,"assignee":{"login":"leafpetersen","id":8484504,"avatar_url":"https://avatars.githubusercontent.com/u/8484504?v=3","gravatar_id":"","url":"https://api.github.com/users/leafpetersen","html_url":"https://github.com/leafpetersen","followers_url":"https://api.github.com/users/leafpetersen/followers","following_url":"https://api.github.com/users/leafpetersen/following{/other_user}","gists_url":"https://api.github.com/users/leafpetersen/gists{/gist_id}","starred_url":"https://api.github.com/users/leafpetersen/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/leafpetersen/subscriptions","organizations_url":"https://api.github.com/users/leafpetersen/orgs","repos_url":"https://api.github.com/users/leafpetersen/repos","events_url":"https://api.github.com/users/leafpetersen/events{/privacy}","received_events_url":"https://api.github.com/users/leafpetersen/received_events","type":"User","site_admin":false},"milestone":null,"comments":0,"created_at":"2015-12-16T01:04:18Z","updated_at":"2015-12-16T01:04:18Z","closed_at":null,"body":"A couple of large projects have observed extremely slow (orders of magnitude) slowdown running strong mode.  This bug is to track and diagnose this.\r\n\r\nI've done some instrumentation of the batch mode analyzer, and what I see is that the individual tasks are not taking longer, but that we are re-resolving dramatically more compilation units.  So this might be a bad interaction with analyzer caching?  Not sure yet.  What I see is as follows.  \r\n\r\nI've instrumented the BuildCompilationUnit task to log whenever it either builds a fresh compilation unit from source, or else pulls a compilation unit out of the cache and re-resolves it.  For a non-strong mode run, I see the following:\r\n\r\nCompilation unit elements built: 2492\r\nCompilation unit elements re-resolved: 9533\r\nUnique compilation elements re-resolved: 2378\r\n\r\nSo there are 2492 compilation units, of which 2378 get re-resolved at some point, on average about 4 times each.\r\n\r\nIn strong mode, letting the process run for a couple of minutes and then killing it, I see:\r\n\r\nCompilation unit elements built: 2492\r\nCompilation unit elements re-resolved: 48811\r\nUnique compilation elements re-resolved: 2378\r\n\r\nSo there are 2492 compilation units, of which 2378 get re-resolved on some point, on average about 20 times each.\r\n\r\nI don't understand entirely what I'm seeing yet - at least all of the same compilation unit elements are being built and then re-resolved, but for some reason a huge number of compilation units are being repeatedly re-resolved.  This looks like it could be a bad cache interaction, but not sure yet.  I'm going to add instrumentation to see how many units are being completed.\r\n\r\n@bwilkerson I don't totally understand what it means for a compilation unit element to be in the cache but need to be re-resolved.  Why does this happen?  Does this mean that something got evicted from the task model cache but not the analyzer cache?  There should be no invalidation happening, I don't think, since we are in batch mode.\r\n\r\ncc @dgrove @skybrian"}}