{"action":"created","issue":{"url":"https://api.github.com/repos/commercialhaskell/stack/issues/1235","repository_url":"https://api.github.com/repos/commercialhaskell/stack","labels_url":"https://api.github.com/repos/commercialhaskell/stack/issues/1235/labels{/name}","comments_url":"https://api.github.com/repos/commercialhaskell/stack/issues/1235/comments","events_url":"https://api.github.com/repos/commercialhaskell/stack/issues/1235/events","html_url":"https://github.com/commercialhaskell/stack/issues/1235","id":113284037,"number":1235,"title":"stack takes too long to find out that there is no work to do","user":{"login":"sjakobi","id":3664523,"avatar_url":"https://avatars.githubusercontent.com/u/3664523?v=3","gravatar_id":"","url":"https://api.github.com/users/sjakobi","html_url":"https://github.com/sjakobi","followers_url":"https://api.github.com/users/sjakobi/followers","following_url":"https://api.github.com/users/sjakobi/following{/other_user}","gists_url":"https://api.github.com/users/sjakobi/gists{/gist_id}","starred_url":"https://api.github.com/users/sjakobi/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/sjakobi/subscriptions","organizations_url":"https://api.github.com/users/sjakobi/orgs","repos_url":"https://api.github.com/users/sjakobi/repos","events_url":"https://api.github.com/users/sjakobi/events{/privacy}","received_events_url":"https://api.github.com/users/sjakobi/received_events","type":"User","site_admin":false},"labels":[{"url":"https://api.github.com/repos/commercialhaskell/stack/labels/further%20investigation%20required","name":"further investigation required","color":"d4c5f9"},{"url":"https://api.github.com/repos/commercialhaskell/stack/labels/type:%20performance","name":"type: performance","color":"fad8c7"}],"state":"open","locked":false,"assignee":{"login":"drwebb","id":178769,"avatar_url":"https://avatars.githubusercontent.com/u/178769?v=3","gravatar_id":"","url":"https://api.github.com/users/drwebb","html_url":"https://github.com/drwebb","followers_url":"https://api.github.com/users/drwebb/followers","following_url":"https://api.github.com/users/drwebb/following{/other_user}","gists_url":"https://api.github.com/users/drwebb/gists{/gist_id}","starred_url":"https://api.github.com/users/drwebb/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/drwebb/subscriptions","organizations_url":"https://api.github.com/users/drwebb/orgs","repos_url":"https://api.github.com/users/drwebb/repos","events_url":"https://api.github.com/users/drwebb/events{/privacy}","received_events_url":"https://api.github.com/users/drwebb/received_events","type":"User","site_admin":false},"assignees":[{"login":"drwebb","id":178769,"avatar_url":"https://avatars.githubusercontent.com/u/178769?v=3","gravatar_id":"","url":"https://api.github.com/users/drwebb","html_url":"https://github.com/drwebb","followers_url":"https://api.github.com/users/drwebb/followers","following_url":"https://api.github.com/users/drwebb/following{/other_user}","gists_url":"https://api.github.com/users/drwebb/gists{/gist_id}","starred_url":"https://api.github.com/users/drwebb/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/drwebb/subscriptions","organizations_url":"https://api.github.com/users/drwebb/orgs","repos_url":"https://api.github.com/users/drwebb/repos","events_url":"https://api.github.com/users/drwebb/events{/privacy}","received_events_url":"https://api.github.com/users/drwebb/received_events","type":"User","site_admin":false}],"milestone":{"url":"https://api.github.com/repos/commercialhaskell/stack/milestones/6","html_url":"https://github.com/commercialhaskell/stack/milestones/P2:%20Should","labels_url":"https://api.github.com/repos/commercialhaskell/stack/milestones/6/labels","id":1191309,"number":6,"title":"P2: Should","description":"Arbitrary date chosen, just to get the milestones to order nicely","creator":{"login":"snoyberg","id":49415,"avatar_url":"https://avatars.githubusercontent.com/u/49415?v=3","gravatar_id":"","url":"https://api.github.com/users/snoyberg","html_url":"https://github.com/snoyberg","followers_url":"https://api.github.com/users/snoyberg/followers","following_url":"https://api.github.com/users/snoyberg/following{/other_user}","gists_url":"https://api.github.com/users/snoyberg/gists{/gist_id}","starred_url":"https://api.github.com/users/snoyberg/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/snoyberg/subscriptions","organizations_url":"https://api.github.com/users/snoyberg/orgs","repos_url":"https://api.github.com/users/snoyberg/repos","events_url":"https://api.github.com/users/snoyberg/events{/privacy}","received_events_url":"https://api.github.com/users/snoyberg/received_events","type":"User","site_admin":false},"open_issues":195,"closed_issues":249,"state":"open","created_at":"2015-07-02T18:20:49Z","updated_at":"2016-09-30T21:43:58Z","due_on":"2016-12-31T08:00:00Z","closed_at":null},"comments":19,"created_at":"2015-10-26T04:31:58Z","updated_at":"2016-09-30T23:29:50Z","closed_at":null,"body":"**Steps to reproduce:**\r\n```\r\n$ cd stack\r\n$ stack build\r\n$ stack build --verbose\r\n```\r\n\r\n**Expected:**\r\nStack quickly realizes that there is no work to do and exits.\r\n\r\n**Actual:**\r\n```\r\nVersion 0.1.7.0, Git revision 7264ef6d99f19091f6521722aa620f4b59dba9e3 (dirty) (2415 commits) x86_64\r\n2015-10-26 04:13:13.885705: [debug] Checking for project config at: /home/simon/src/stack/stack.yaml @(stack_FHzONQT9HI3ATX2xQH198L:Stack.Config src/Stack/Config.hs:554:9)\r\n2015-10-26 04:13:13.885916: [debug] Loading project config file stack.yaml @(stack_FHzONQT9HI3ATX2xQH198L:Stack.Config src/Stack/Config.hs:577:13)\r\n2015-10-26 04:13:13.887741: [debug] Run process: ldd /home/simon/.local/bin/stack @(stack_FHzONQT9HI3ATX2xQH198L:System.Process.Read src/System/Process/Read.hs:272:3)\r\n2015-10-26 04:13:13.904957: [debug] Trying to decode /home/simon/.stack/build-plan-cache/x86_64-linux/lts-3.7.cache @(stack_FHzONQT9HI3ATX2xQH198L:Data.Binary.VersionTagged src/Data/Binary/VersionTagged.hs:53:5)\r\n2015-10-26 04:13:13.927123: [debug] Success decoding /home/simon/.stack/build-plan-cache/x86_64-linux/lts-3.7.cache @(stack_FHzONQT9HI3ATX2xQH198L:Data.Binary.VersionTagged src/Data/Binary/VersionTagged.hs:62:13)\r\n2015-10-26 04:13:13.92793: [debug] Run process: ghc --info @(stack_FHzONQT9HI3ATX2xQH198L:System.Process.Read src/System/Process/Read.hs:272:3)\r\n2015-10-26 04:13:13.993673: [debug] Run process: ghc --numeric-version @(stack_FHzONQT9HI3ATX2xQH198L:System.Process.Read src/System/Process/Read.hs:272:3)\r\n2015-10-26 04:13:14.032049: [debug] Run process: ghc-pkg --no-user-package-db field --simple-output Cabal version @(stack_FHzONQT9HI3ATX2xQH198L:System.Process.Read src/System/Process/Read.hs:272:3)\r\n2015-10-26 04:13:14.0626: [debug] Run process: ghc-pkg --no-user-package-db list --global @(stack_FHzONQT9HI3ATX2xQH198L:System.Process.Read src/System/Process/Read.hs:272:3)\r\n2015-10-26 04:13:14.094419: [debug] Run process: locale -a @(stack_FHzONQT9HI3ATX2xQH198L:System.Process.Read src/System/Process/Read.hs:272:3)\r\n2015-10-26 04:13:14.115801: [debug] Checking resolver: lts-3.7 @(stack_FHzONQT9HI3ATX2xQH198L:Stack.Build.Source src/Stack/Build/Source.hs:162:17)\r\n2015-10-26 04:13:14.115972: [debug] Trying to decode /home/simon/.stack/build-plan-cache/x86_64-linux/lts-3.7.cache @(stack_FHzONQT9HI3ATX2xQH198L:Data.Binary.VersionTagged src/Data/Binary/VersionTagged.hs:53:5)\r\n2015-10-26 04:13:14.139067: [debug] Success decoding /home/simon/.stack/build-plan-cache/x86_64-linux/lts-3.7.cache @(stack_FHzONQT9HI3ATX2xQH198L:Data.Binary.VersionTagged src/Data/Binary/VersionTagged.hs:62:13)\r\n2015-10-26 04:13:14.157555: [debug] Trying to decode /home/simon/.stack/indices/Hackage/00-index.cache @(stack_FHzONQT9HI3ATX2xQH198L:Data.Binary.VersionTagged src/Data/Binary/VersionTagged.hs:53:5)\r\n2015-10-26 04:13:14.726689: [debug] Success decoding /home/simon/.stack/indices/Hackage/00-index.cache @(stack_FHzONQT9HI3ATX2xQH198L:Data.Binary.VersionTagged src/Data/Binary/VersionTagged.hs:62:13)\r\n2015-10-26 04:13:14.899557: [debug] Run process: ghc-pkg --global --no-user-package-db dump --expand-pkgroot @(stack_FHzONQT9HI3ATX2xQH198L:System.Process.Read src/System/Process/Read.hs:272:3)\r\n2015-10-26 04:13:14.98411: [debug] Run process: ghc-pkg --user --no-user-package-db --package-db /home/simon/.stack/snapshots/x86_64-linux/lts-3.7/7.10.2/pkgdb/ dump --expand-pkgroot @(stack_FHzONQT9HI3ATX2xQH198L:System.Process.Read src/System/Process/Read.hs:272:3)\r\n2015-10-26 04:13:15.152178: [debug] Run process: ghc-pkg --user --no-user-package-db --package-db /home/simon/src/stack/.stack-work/install/x86_64-linux/lts-3.7/7.10.2/pkgdb/ dump --expand-pkgroot @(stack_FHzONQT9HI3ATX2xQH198L:System.Process.Read src/System/Process/Read.hs:272:3)\r\n2015-10-26 04:13:15.197502: [debug] Ignoring package iso8601-time, from (InstalledTo Local,\"/home/simon/src/stack/.stack-work/install/x86_64-linux/lts-3.7/7.10.2/pkgdb/\"), due to  it being unknown to the resolver / extra-deps. @(stack_FHzONQT9HI3ATX2xQH198L:Stack.Build.Installed src/Stack/Build/Installed.hs:189:5)\r\n2015-10-26 04:13:15.198028: [debug] Trying to decode /home/simon/.stack/indices/Hackage/00-index.cache @(stack_FHzONQT9HI3ATX2xQH198L:Data.Binary.VersionTagged src/Data/Binary/VersionTagged.hs:53:5)\r\n2015-10-26 04:13:15.71894: [debug] Success decoding /home/simon/.stack/indices/Hackage/00-index.cache @(stack_FHzONQT9HI3ATX2xQH198L:Data.Binary.VersionTagged src/Data/Binary/VersionTagged.hs:62:13)\r\n2015-10-26 04:13:15.719419: [debug] Trying to decode /home/simon/.stack/indices/Hackage/00-index.cache @(stack_FHzONQT9HI3ATX2xQH198L:Data.Binary.VersionTagged src/Data/Binary/VersionTagged.hs:53:5)\r\n2015-10-26 04:13:16.263889: [debug] Success decoding /home/simon/.stack/indices/Hackage/00-index.cache @(stack_FHzONQT9HI3ATX2xQH198L:Data.Binary.VersionTagged src/Data/Binary/VersionTagged.hs:62:13)\r\n2015-10-26 04:13:16.415685: [debug] Run process: ghc-pkg --no-user-package-db list --global @(stack_FHzONQT9HI3ATX2xQH198L:System.Process.Read src/System/Process/Read.hs:272:3)\r\n```\r\nThis takes about 2.6s on my machine. Among other things stack decodes ~/.stack/indices/Hackage/00-index.cache three times which accounts for about 1.6s.\r\n\r\nIs all this work really necessary to discover that there is no building to be done?"},"comment":{"url":"https://api.github.com/repos/commercialhaskell/stack/issues/comments/250874961","html_url":"https://github.com/commercialhaskell/stack/issues/1235#issuecomment-250874961","issue_url":"https://api.github.com/repos/commercialhaskell/stack/issues/1235","id":250874961,"user":{"login":"mgsloan","id":22570,"avatar_url":"https://avatars.githubusercontent.com/u/22570?v=3","gravatar_id":"","url":"https://api.github.com/users/mgsloan","html_url":"https://github.com/mgsloan","followers_url":"https://api.github.com/users/mgsloan/followers","following_url":"https://api.github.com/users/mgsloan/following{/other_user}","gists_url":"https://api.github.com/users/mgsloan/gists{/gist_id}","starred_url":"https://api.github.com/users/mgsloan/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/mgsloan/subscriptions","organizations_url":"https://api.github.com/users/mgsloan/orgs","repos_url":"https://api.github.com/users/mgsloan/repos","events_url":"https://api.github.com/users/mgsloan/events{/privacy}","received_events_url":"https://api.github.com/users/mgsloan/received_events","type":"User","site_admin":false},"created_at":"2016-09-30T23:29:50Z","updated_at":"2016-09-30T23:29:50Z","body":"Looks like the time is spent in `getPackageFiles`.  I've pushed a commit adding a bit of debug logging here.  For `stack` itself, it takes half a second:\r\n\r\n![2016-09-30-162846_1091x124_scrot](https://cloud.githubusercontent.com/assets/22570/19009667/1069c29c-872b-11e6-94b7-af632d67cbbe.png)\r\n"}}
{"actor":{"display_login":"mgsloan"}}