search

google-code-export / psutil

Automatically exported from code.google.com/p/psutil
Other
0 stars 0 forks source link

Process.get_cpu_percent() useless calls to system-wide cpu_times() #477

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago 
I wrote a script that prints in real time the top 10 processes, sorted by CPU 
usage (just like top).

# init CPU meters
for proc in psutil.process_iter():
   proc.get_cpu_percent(interval=None)

for i in range(100):
    time.sleep(1)
    for proc in psutil.process_iter():
        cpu = proc.get_cpu_percent(interval=None)
    ...

The above hogs a whopping 29% CPU. This is what cProfile says:

         2525223 function calls in 129.009 CPU seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
      100  100.002    1.000  100.002    1.000 {time.sleep}
    59798    0.714    0.000   20.810    0.000 build/bdist.linux-x86_64/egg/psutil/__init__.py:679(get_cpu_percent)
    59798    0.158    0.000   16.206    0.000 build/bdist.linux-x86_64/egg/psutil/__init__.py:1166(cpu_times)
    59798    1.293    0.000   16.048    0.000 build/bdist.linux-x86_64/egg/psutil/_pslinux.py:270(get_system_cpu_times)
   119596   13.827    0.000   13.827    0.000 {method 'readline' of 'file' objects}
   194235    0.487    0.000   11.195    0.000 build/bdist.linux-x86_64/egg/psutil/_pslinux.py:460(wrapper)
    59898    0.197    0.000    4.329    0.000 build/bdist.linux-x86_64/egg/psutil/__init__.py:1031(process_iter)
    59795    0.139    0.000    3.815    0.000 build/bdist.linux-x86_64/egg/psutil/__init__.py:830(is_running)
    59798    0.805    0.000    3.566    0.000 build/bdist.linux-x86_64/egg/psutil/_pslinux.py:576(get_cpu_times)
    59802    0.717    0.000    3.494    0.000 build/bdist.linux-x86_64/egg/psutil/_pslinux.py:597(get_process_create_time)
    59798    0.091    0.000    3.359    0.000 build/bdist.linux-x86_64/egg/psutil/__init__.py:760(get_ext_memory_info)
    59798    1.210    0.000    3.157    0.000 build/bdist.linux-x86_64/egg/psutil/_pslinux.py:626(get_ext_memory_info)
   254133    2.902    0.000    2.902    0.000 {open}
   134433    2.726    0.000    2.726    0.000 {method 'read' of 'file' objects}
   254129    1.601    0.000    1.601    0.000 {method 'close' of 'file' objects}
   254329    0.697    0.000    0.697    0.000 {method 'split' of 'str' objects}

The problem is that every single call to get_cpu_percent() internally invokes 
sum(cpu_times()). With maybe some weird exceptions (hybernation?) that should 
be pretty much the same as calling time.time() and multiply by the number of 
CPUs - which is MUCH faster.

Same benchmark, replacing get_cpu_percent() with get_cpu_times(), I get a more 
reasonable 8% CPU usage:

         1323713 function calls in 108.063 CPU seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
      100  100.000    1.000  100.000    1.000 {time.sleep}
   119751    0.328    0.000    7.363    0.000 build/bdist.linux-x86_64/egg/psutil/_pslinux.py:460(wrapper)
    59975    0.165    0.000    4.350    0.000 build/bdist.linux-x86_64/egg/psutil/__init__.py:1031(process_iter)
    59869    0.140    0.000    3.884    0.000 build/bdist.linux-x86_64/egg/psutil/__init__.py:830(is_running)
    59875    0.094    0.000    3.712    0.000 build/bdist.linux-x86_64/egg/psutil/__init__.py:743(get_cpu_times)
    59876    0.680    0.000    3.579    0.000 build/bdist.linux-x86_64/egg/psutil/_pslinux.py:597(get_process_create_time)
    59875    0.788    0.000    3.457    0.000 build/bdist.linux-x86_64/egg/psutil/_pslinux.py:576(get_cpu_times)
   119750    2.677    0.000    2.677    0.000 {method 'read' of 'file' objects}
   119751    1.340    0.000    1.340    0.000 {open}
   119750    0.546    0.000    0.546    0.000 {method 'close' of 'file' objects}
   119750    0.440    0.000    0.440    0.000 {method 'split' of 'str' objects}
    59875    0.297    0.000    0.297    0.000 {method 'rfind' of 'str' objects}
      100    0.000    0.000    0.235    0.002 build/bdist.linux-x86_64/egg/psutil/__init__.py:1016(get_pid_list)
      100    0.140    0.001    0.234    0.002 build/bdist.linux-x86_64/egg/psutil/_pslinux.py:359(get_pid_list)

I'm sure it's possible to improve even further, as top only uses 1% - not sure 
how tough.

Original issue reported on code.google.com by crusade...@gmail.com on 13 Feb 2014 at 1:31

GoogleCodeExporter commented 9 years ago 
> The problem is that every single call to get_cpu_percent() internally invokes 
> sum(cpu_times()). With maybe some weird exceptions (hybernation?) that should 
be
> pretty much the same as calling time.time() and multiply by the number of 
CPUs - 
> which is MUCH faster.

Mmm are you sure? The two results look very different:

>>> sum(psutil.cpu_times())
459405.7900000001
>>> time.time()
1392336739.063232
>>> 

Anyway, I agree calculating sum(cpu_times()) on every iteration, for every 
process, is sub-optimal.
I see two solutions, and I still don't know whether I like them:

1) - allow to pass system-wide CPU times as an argument as in 
"cpu_percent(self, interval=None, cputimes=None)"

2) - cache sum(cpu_times()) value in a global constant and update it every 0.1 
seconds or something

A third option might be reimplementing psutil.cpu_times() in C and avoid to 
read a file in /proc, but I'm not sure if that's even possible.

Original comment by g.rodola on 14 Feb 2014 at 12:24

GoogleCodeExporter commented 9 years ago 
Well, duh? Of course they're different, one is the seconds from 1970, the other 
is the seconds from the last boot. However, since you only care about 
differentials, they're perfectly interchangeable.

t1 = time.time()
t2 = sum(psutil.cpu_times())
time.sleep(10)
t1 = time.time() - t1
t2 = sum(psutil.cpu_times()) - t2
print t1 * psutil.NUM_CPUS
print t2

output:
319.998527527
319.979999989

Original comment by crusade...@gmail.com on 14 Feb 2014 at 11:45

GoogleCodeExporter commented 9 years ago 
Mmm, interesting. So are you suggesting to replace all sum(psutil.cpu_times()) 
occurrences with time.time()?
I just tried that and that appears to produce higher CPU percentages which no 
longer reflect what's shown by top.
Maybe you want to provide a patch?

Original comment by g.rodola on 14 Feb 2014 at 1:33

GoogleCodeExporter commented 9 years ago 
Note: in order to observe CPU usage of the ongoing processes I simply used 
examples/top.py script.

Original comment by g.rodola on 14 Feb 2014 at 1:35

GoogleCodeExporter commented 9 years ago 
Did you remember to multiply time.time() * psutil.NUM_CPUS?

Original comment by crusade...@gmail.com on 14 Feb 2014 at 3:50

GoogleCodeExporter commented 9 years ago 
You're right.
I committed this change in revision 44329a06f95e.
According to my benchmarks Process.cpu_percent() should now be about 30% faster 
on Linux.
This was a great catch, thanks.

Original comment by g.rodola on 15 Feb 2014 at 2:15

GoogleCodeExporter commented 9 years ago 
Closing out as fixed as 2.0.0 version is finally out.

Original comment by g.rodola on 10 Mar 2014 at 11:36