[GHC] #8224: Excessive system time -- new IO manager problem?
GHC
ghc-devs at haskell.org
Tue Nov 12 18:06:42 UTC 2013
#8224: Excessive system time -- new IO manager problem?
-------------------------------------+-------------------------------------
Reporter: rrnewton | Owner:
Type: bug | Status: new
Priority: high | Milestone: 7.8.1
Component: Runtime System | Version: 7.7
Resolution: | Keywords: IO Manager,
Operating System: Linux | System Time
Type of failure: Runtime | Architecture: x86_64 (amd64)
performance bug | Difficulty: Unknown
Test Case: | Blocked By:
Blocking: | Related Tickets:
-------------------------------------+-------------------------------------
Comment (by AndreasVoellmy):
I'm not sure about the 8 minutes problem, but the 200ms system time for
the empty program does indeed seem to be related to the parallel IO
manager changes. I just modified the IO manager to start only one epoll
instance and I get about 50 ms system time, whereas with HEAD I get about
200ms still. I will upload the patch to make the IO manager use just one
poller in case anyone else wants to try it.
Some data... With just one poller, strace -C gives:
{{{
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
100.00 0.000046 1 40 getrusage
0.00 0.000000 0 7 read
0.00 0.000000 0 1 write
0.00 0.000000 0 51 42 open
0.00 0.000000 0 9 close
0.00 0.000000 0 8 6 stat
0.00 0.000000 0 8 fstat
0.00 0.000000 0 90 mmap
0.00 0.000000 0 46 mprotect
0.00 0.000000 0 15 munmap
0.00 0.000000 0 16 brk
0.00 0.000000 0 12 rt_sigaction
0.00 0.000000 0 7 rt_sigprocmask
0.00 0.000000 0 1 rt_sigreturn
0.00 0.000000 0 1 ioctl
0.00 0.000000 0 8 8 access
0.00 0.000000 0 1 pipe
0.00 0.000000 0 32 clone
0.00 0.000000 0 1 execve
0.00 0.000000 0 8 fcntl
0.00 0.000000 0 1 getrlimit
0.00 0.000000 0 1 getuid
0.00 0.000000 0 1 getgid
0.00 0.000000 0 1 geteuid
0.00 0.000000 0 1 getegid
0.00 0.000000 0 1 arch_prctl
0.00 0.000000 0 101 2 futex
0.00 0.000000 0 1 epoll_create
0.00 0.000000 0 1 set_tid_address
0.00 0.000000 0 1 timer_create
0.00 0.000000 0 2 timer_settime
0.00 0.000000 0 1 timer_delete
0.00 0.000000 0 2 epoll_ctl
0.00 0.000000 0 1 set_robust_list
0.00 0.000000 0 1 eventfd2
------ ----------- ----------- --------- --------- ----------------
100.00 0.000046 479 58 total
}}}
On the other hand, with N pollers (i.e. HEAD) strace -C gives:
{{{
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
86.21 0.002356 21 114 2 futex
8.67 0.000237 18 13 rt_sigaction
5.12 0.000140 1 263 fcntl
0.00 0.000000 0 8 read
0.00 0.000000 0 1 write
0.00 0.000000 0 52 42 open
0.00 0.000000 0 10 close
0.00 0.000000 0 8 6 stat
0.00 0.000000 0 9 fstat
0.00 0.000000 0 74 mmap
0.00 0.000000 0 46 mprotect
0.00 0.000000 0 10 munmap
0.00 0.000000 0 19 brk
0.00 0.000000 0 5 rt_sigprocmask
0.00 0.000000 0 1 rt_sigreturn
0.00 0.000000 0 1 ioctl
0.00 0.000000 0 8 8 access
0.00 0.000000 0 33 pipe
0.00 0.000000 0 32 clone
0.00 0.000000 0 1 execve
0.00 0.000000 0 1 getrlimit
0.00 0.000000 0 1 getuid
0.00 0.000000 0 1 getgid
0.00 0.000000 0 1 geteuid
0.00 0.000000 0 1 getegid
0.00 0.000000 0 1 arch_prctl
0.00 0.000000 0 32 epoll_create
0.00 0.000000 0 1 set_tid_address
0.00 0.000000 0 1 timer_create
0.00 0.000000 0 2 timer_settime
0.00 0.000000 0 1 timer_delete
0.00 0.000000 0 4 clock_gettime
0.00 0.000000 0 64 epoll_ctl
0.00 0.000000 0 1 set_robust_list
0.00 0.000000 0 33 eventfd2
------ ----------- ----------- --------- --------- ----------------
100.00 0.002733 853 58 total
}}}
--
Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/8224#comment:12>
GHC <http://www.haskell.org/ghc/>
The Glasgow Haskell Compiler
More information about the ghc-tickets
mailing list