Opened 6 years ago

Closed 4 years ago

#9105 closed bug (fixed)

Profiling binary consumes CPU even when idle on Linux.

Reported by: robinp Owned by:
Priority: normal Milestone: 8.0.1
Component: Runtime System Version: 7.8.2
Keywords: Cc: simonmar
Operating System: Linux Architecture: x86
Type of failure: Runtime performance bug Test Case:
Blocked By: Blocking:
Related Tickets: Differential Rev(s): Phab:D1822, Phab:D1844
Wiki Page:

Description (last modified by bgamari)

The program is

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.

Change History (12)

comment:1 Changed 5 years ago by thomie

Cc: simonmar added
Component: CompilerRuntime System
Owner: set to simonmar
Type of failure: None/UnknownRuntime performance bug

comment:2 Changed 4 years ago by bgamari

Description: modified (diff)

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.

comment:3 Changed 4 years ago by bgamari

Differential Rev(s): Phab:D1822
Status: newpatch

See Phab:D1822 for a proposed fix.

comment:4 Changed 4 years ago by bgamari

Owner: changed from simonmar to bgamari

comment:5 Changed 4 years ago by Ben Gamari <ben@…>

In b01288d/ghc:

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

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:

GHC Trac Issues: #9105

comment:6 Changed 4 years ago by bgamari

Milestone: 8.0.1
Status: patchmerge

comment:7 Changed 4 years ago by bgamari

Resolution: fixed
Status: mergeclosed

comment:8 Changed 4 years ago by bgamari

Owner: bgamari deleted
Resolution: fixed
Status: closednew

Unfortunately this fix wasn't quite right.

comment:9 Changed 4 years ago by bgamari

Differential Rev(s): Phab:D1822Phab:D1822, Phab:D1844
Status: newpatch

See Phab:D1844 for another attempt at a fix.

comment:10 Changed 4 years ago by Ben Gamari <ben@…>

In 1c6130d/ghc:

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:

GHC Trac Issues: #9105

comment:11 Changed 4 years ago by bgamari

Status: patchmerge

comment:12 Changed 4 years ago by bgamari

Resolution: fixed
Status: mergeclosed
Note: See TracTickets for help on using tickets.