[GHC] #9105: Profiling binary consumes CPU even when idle on Linux.
#9105: Profiling binary consumes CPU even when idle on Linux. ----------------------------+--------------------------------- Reporter: robinp | Owner: Type: bug | Status: new Priority: normal | Milestone: Component: Compiler | Version: 7.8.2 Keywords: | Operating System: Linux Architecture: x86 | Type of failure: None/Unknown Difficulty: Unknown | Test Case: Blocked By: | Blocking: Related Tickets: | ----------------------------+--------------------------------- The program is main = forever $ threadDelay 1000000 >> return () . Compiled with 32bit GHC 7.6.3 or 7.8.2 on Debian (inside a VM), GHC 7.4.1 on Ubuntu (not VM). The non-profiling binary doesn't consume CPU, the profiling does ~10% (of a 2Ghz machine). Running with +RTS -I0, so this is not the idle gc. When strace-ing, the profiling one seems to receive a constant flow of SIGVTALRM, while the normal receives one burst each second. I see I can switch off "master tick interval" with -V0, and then CPU is not used, but the consequences of this are not very well documented (apart from context switching becoming deterministic). Interestingly, if I compile using profiling on Windows (latest haskell- platform, 64bit), it doesn't use more CPU than the non-profiling. So, the question is, why does this happen on Linux, and if it can be avoided somehow. -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/9105> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#9105: Profiling binary consumes CPU even when idle on Linux. -------------------------------------+------------------------------------- Reporter: robinp | Owner: simonmar Type: bug | Status: new Priority: normal | Milestone: Component: Runtime System | Version: 7.8.2 Resolution: | Keywords: Operating System: Linux | Architecture: x86 Type of failure: Runtime | Test Case: performance bug | Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Wiki Page: | -------------------------------------+------------------------------------- @@ -2,2 +2,6 @@ - main = forever $ threadDelay 1000000 >> return () . - + {{{#!hs + import Control.Concurrent + import Control.Monad (forever) + main :: IO () + main = forever $ threadDelay 1000000 >> return () + }}} @@ -7,1 +11,1 @@ - a 2Ghz machine). Running with +RTS -I0, so this is not the idle gc. + a 2Ghz machine). Running with `+RTS -I0`, so this is not the idle gc. @@ -12,1 +16,1 @@ - I see I can switch off "master tick interval" with -V0, and then CPU is + I see I can switch off "master tick interval" with `-V0`, and then CPU is @@ -17,1 +21,1 @@ - platform, 64bit), it doesn't use more CPU than the non-profiling. + platform, 64-bit), it doesn't use more CPU than the non-profiling. New description: The program is {{{#!hs import Control.Concurrent import Control.Monad (forever) main :: IO () main = forever $ threadDelay 1000000 >> return () }}} Compiled with 32bit GHC 7.6.3 or 7.8.2 on Debian (inside a VM), GHC 7.4.1 on Ubuntu (not VM). The non-profiling binary doesn't consume CPU, the profiling does ~10% (of a 2Ghz machine). Running with `+RTS -I0`, so this is not the idle gc. When strace-ing, the profiling one seems to receive a constant flow of SIGVTALRM, while the normal receives one burst each second. I see I can switch off "master tick interval" with `-V0`, and then CPU is not used, but the consequences of this are not very well documented (apart from context switching becoming deterministic). Interestingly, if I compile using profiling on Windows (latest haskell- platform, 64-bit), it doesn't use more CPU than the non-profiling. So, the question is, why does this happen on Linux, and if it can be avoided somehow. -- Comment (by bgamari): If I'm not mistaken this is an expected result of our profiler, which is a sampling profiler. Looking at a `perf` profile reveals that this CPU time is largely spent in `handle_tick`. Diving in here we find that the first thing this function does is call `handleProfTick`, which does a variety of book-keeping to schedule the next time/heap sample. There is yet another difference, however: in the non-profiling case the tick timer is stopped when the process is known to be idle. In the profiling case we can't do this, to ensure that our profile isn't skewed. However, I believe it would be safe to nevertheless disable the compiler if you didn't run the executable with `+RTS -h` or `+RTS -p`. This is probably something that we should do. -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/9105#comment:2> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#9105: Profiling binary consumes CPU even when idle on Linux. -------------------------------------+------------------------------------- Reporter: robinp | Owner: simonmar Type: bug | Status: patch Priority: normal | Milestone: Component: Runtime System | Version: 7.8.2 Resolution: | Keywords: Operating System: Linux | Architecture: x86 Type of failure: Runtime | Test Case: performance bug | Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Phab:D1822 Wiki Page: | -------------------------------------+------------------------------------- Changes (by bgamari): * status: new => patch * differential: => Phab:D1822 Comment: See Phab:D1822 for a proposed fix. -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/9105#comment:3> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#9105: Profiling binary consumes CPU even when idle on Linux. -------------------------------------+------------------------------------- Reporter: robinp | Owner: bgamari Type: bug | Status: patch Priority: normal | Milestone: Component: Runtime System | Version: 7.8.2 Resolution: | Keywords: Operating System: Linux | Architecture: x86 Type of failure: Runtime | Test Case: performance bug | Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Phab:D1822 Wiki Page: | -------------------------------------+------------------------------------- Changes (by bgamari): * owner: simonmar => bgamari -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/9105#comment:4> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#9105: Profiling binary consumes CPU even when idle on Linux. -------------------------------------+------------------------------------- Reporter: robinp | Owner: bgamari Type: bug | Status: patch Priority: normal | Milestone: Component: Runtime System | Version: 7.8.2 Resolution: | Keywords: Operating System: Linux | Architecture: x86 Type of failure: Runtime | Test Case: performance bug | Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Phab:D1822 Wiki Page: | -------------------------------------+------------------------------------- Comment (by Ben Gamari <ben@…>): In [changeset:"b01288d509b0f9e45f23ae48f2366f85f489089c/ghc" b01288d/ghc]: {{{ #!CommitTicketReference repository="ghc" revision="b01288d509b0f9e45f23ae48f2366f85f489089c" rts: Disable tick timer unless really needed Trac #9105 notes significant CPU usage by an otherwise idle process when compiled with profiling. The reason for this is that we keep the tick timer active in the profiling RTS even if profiling wasn't requested at runtime. If the user requests any sort of profiling then we need to keep the timer active to ensure that samples are collected. Test Plan: Validate, check CPU usage, ensure profiling still works Reviewers: simonmar, austin Reviewed By: simonmar, austin Subscribers: thomie Differential Revision: https://phabricator.haskell.org/D1822 GHC Trac Issues: #9105 }}} -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/9105#comment:5> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#9105: Profiling binary consumes CPU even when idle on Linux. -------------------------------------+------------------------------------- Reporter: robinp | Owner: bgamari Type: bug | Status: merge Priority: normal | Milestone: 8.0.1 Component: Runtime System | Version: 7.8.2 Resolution: | Keywords: Operating System: Linux | Architecture: x86 Type of failure: Runtime | Test Case: performance bug | Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Phab:D1822 Wiki Page: | -------------------------------------+------------------------------------- Changes (by bgamari): * status: patch => merge * milestone: => 8.0.1 -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/9105#comment:6> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#9105: Profiling binary consumes CPU even when idle on Linux. -------------------------------------+------------------------------------- Reporter: robinp | Owner: bgamari Type: bug | Status: closed Priority: normal | Milestone: 8.0.1 Component: Runtime System | Version: 7.8.2 Resolution: fixed | Keywords: Operating System: Linux | Architecture: x86 Type of failure: Runtime | Test Case: performance bug | Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Phab:D1822 Wiki Page: | -------------------------------------+------------------------------------- Changes (by bgamari): * status: merge => closed * resolution: => fixed Comment: Merged to `ghc-8.0` as 26a9f13ca4f602749f0f00388a145badbf7c27dd. -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/9105#comment:7> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#9105: Profiling binary consumes CPU even when idle on Linux. -------------------------------------+------------------------------------- Reporter: robinp | Owner: Type: bug | Status: new Priority: normal | Milestone: 8.0.1 Component: Runtime System | Version: 7.8.2 Resolution: | Keywords: Operating System: Linux | Architecture: x86 Type of failure: Runtime | Test Case: performance bug | Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Phab:D1822 Wiki Page: | -------------------------------------+------------------------------------- Changes (by bgamari): * owner: bgamari => * status: closed => new * resolution: fixed => Comment: Unfortunately this fix wasn't quite right. -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/9105#comment:8> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#9105: Profiling binary consumes CPU even when idle on Linux. -------------------------------------+------------------------------------- Reporter: robinp | Owner: Type: bug | Status: patch Priority: normal | Milestone: 8.0.1 Component: Runtime System | Version: 7.8.2 Resolution: | Keywords: Operating System: Linux | Architecture: x86 Type of failure: Runtime | Test Case: performance bug | Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Phab:D1822, Wiki Page: | Phab:D1844 -------------------------------------+------------------------------------- Changes (by bgamari): * status: new => patch * differential: Phab:D1822 => Phab:D1822, Phab:D1844 Comment: See Phab:D1844 for another attempt at a fix. -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/9105#comment:9> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#9105: Profiling binary consumes CPU even when idle on Linux. -------------------------------------+------------------------------------- Reporter: robinp | Owner: Type: bug | Status: patch Priority: normal | Milestone: 8.0.1 Component: Runtime System | Version: 7.8.2 Resolution: | Keywords: Operating System: Linux | Architecture: x86 Type of failure: Runtime | Test Case: performance bug | Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Phab:D1822, Wiki Page: | Phab:D1844 -------------------------------------+------------------------------------- Comment (by Ben Gamari <ben@…>): In [changeset:"1c6130d91420dc835c281bc9b13d603b7aa49b59/ghc" 1c6130d/ghc]: {{{ #!CommitTicketReference repository="ghc" revision="1c6130d91420dc835c281bc9b13d603b7aa49b59" rts/Timer: Actually fix #9105 jberthold astutely pointed out that the previous fix (D1822) could not have possibly fixed the issue as the patch would only have had any effect if !PROFILING. Test Plan: Check for reduced CPU usage when compiled with `-prof` but without `+RTS -p` Reviewers: simonmar, austin, jberthold Reviewed By: simonmar, jberthold Subscribers: simonmar, thomie Differential Revision: https://phabricator.haskell.org/D1844 GHC Trac Issues: #9105 }}} -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/9105#comment:10> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#9105: Profiling binary consumes CPU even when idle on Linux. -------------------------------------+------------------------------------- Reporter: robinp | Owner: Type: bug | Status: merge Priority: normal | Milestone: 8.0.1 Component: Runtime System | Version: 7.8.2 Resolution: | Keywords: Operating System: Linux | Architecture: x86 Type of failure: Runtime | Test Case: performance bug | Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Phab:D1822, Wiki Page: | Phab:D1844 -------------------------------------+------------------------------------- Changes (by bgamari): * status: patch => merge -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/9105#comment:11> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#9105: Profiling binary consumes CPU even when idle on Linux. -------------------------------------+------------------------------------- Reporter: robinp | Owner: Type: bug | Status: closed Priority: normal | Milestone: 8.0.1 Component: Runtime System | Version: 7.8.2 Resolution: fixed | Keywords: Operating System: Linux | Architecture: x86 Type of failure: Runtime | Test Case: performance bug | Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Phab:D1822, Wiki Page: | Phab:D1844 -------------------------------------+------------------------------------- Changes (by bgamari): * status: merge => closed * resolution: => fixed Comment: Merged as 7d123cc87ba69d96f4e32921549201537abe118b. -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/9105#comment:12> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
participants (1)
-
GHC