#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