claudyus / LXC-Web-Panel

LXC Web Panel improved for lxc 1.0+
http://claudyus.github.io/LXC-Web-Panel/
Other
221 stars 68 forks source link

Slowness on Debian Jessie, pt. 2 #31

Closed kenzodeluxe closed 9 years ago

kenzodeluxe commented 10 years ago

This is in reference to https://github.com/claudyus/LXC-Web-Panel/issues/12, especially https://github.com/claudyus/LXC-Web-Panel/issues/12#issuecomment-54465651:

Here's some output with the --profiling option:

--------------------------------------------------------------------------------
PATH: '/home'
         465467 function calls (445754 primitive calls) in 89.247 seconds

   Ordered by: internal time, call count
   List reduced from 756 to 30 due to restriction <30>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
      209   87.931    0.421   87.931    0.421 {method 'read' of 'file' objects}
      200    0.531    0.003    0.531    0.003 {posix.read}
      200    0.115    0.001    0.115    0.001 {posix.fork}
     8149    0.038    0.000    0.038    0.000 {posix.stat}
      200    0.035    0.000    0.698    0.003 /usr/lib/python2.7/subprocess.py:1187(_execute_child)
       53    0.035    0.001    0.075    0.001 /usr/lib/python2.7/ConfigParser.py:464(_read)
    12244    0.025    0.000    0.025    0.000 {method 'match' of '_sre.SRE_Pattern' objects}
     2497    0.024    0.000    0.029    0.000 /usr/local/lib/python2.7/dist-packages/werkzeug/urls.py:374(url_quote)
       74    0.020    0.000    0.587    0.008 /usr/local/lib/python2.7/dist-packages/lwp-0.6_-py2.7.egg/lwp/lxclite/__init__.py:93(ls)
    69535    0.016    0.000    0.018    0.000 {isinstance}
    15214    0.015    0.000    0.034    0.000 /usr/local/lib/python2.7/dist-packages/jinja2/nodes.py:164(iter_child_nodes)
    24837    0.012    0.000    0.015    0.000 /usr/local/lib/python2.7/dist-packages/jinja2/nodes.py:148(iter_fields)
       53    0.010    0.000    0.443    0.008 /usr/local/lib/python2.7/dist-packages/lwp-0.6_-py2.7.egg/lwp/__init__.py:230(get_container_settings)
       77    0.010    0.000    0.010    0.000 {posix.listdir}
     2128    0.009    0.000    0.030    0.000 /usr/local/lib/python2.7/dist-packages/jinja2/lexer.py:593(tokeniter)
      200    0.009    0.000    0.727    0.004 /usr/lib/python2.7/subprocess.py:650(__init__)
    25113    0.009    0.000    0.010    0.000 {getattr}
     8515    0.008    0.000    0.008    0.000 {method 'split' of 'str' objects}
       37    0.008    0.000   87.903    2.376 /usr/local/lib/python2.7/dist-packages/lwp-0.6_-py2.7.egg/lwp/lxclite/__init__.py:111(listx)
     4218    0.007    0.000    0.033    0.000 /usr/lib/python2.7/genericpath.py:38(isdir)
     8357    0.007    0.000    0.007    0.000 {method 'format' of 'str' objects}
      200    0.007    0.000   88.685    0.443 /usr/lib/python2.7/subprocess.py:544(check_output)
     3531    0.007    0.000    0.007    0.000 /usr/lib/python2.7/collections.py:54(__setitem__)
      552    0.007    0.000    0.032    0.000 /usr/local/lib/python2.7/dist-packages/werkzeug/urls.py:762(url_join)
     3922    0.007    0.000    0.030    0.000 /usr/lib/python2.7/genericpath.py:26(isfile)
      618    0.007    0.000    0.014    0.000 /usr/lib/python2.7/ConfigParser.py:590(get)
      200    0.006    0.000    0.006    0.000 {posix.fdopen}
     1600    0.006    0.000    0.006    0.000 {fcntl.fcntl}
      200    0.006    0.000   87.950    0.440 /usr/lib/python2.7/subprocess.py:768(communicate)
      552    0.006    0.000    0.046    0.000 /usr/local/lib/python2.7/dist-packages/werkzeug/routing.py:703(build)

I am however using the latest version from Git including https://github.com/claudyus/LXC-Web-Panel/commit/e3e6ee67fd93727c37c965ca4dc9939a09d07b5f, https://github.com/claudyus/LXC-Web-Panel/commit/1f123825cb43af9b02a2f4b886bb2fcfdda2b42c and https://github.com/claudyus/LXC-Web-Panel/commit/00a36f35560786b656682245f86de4379b697198:

# md5sum /usr/local/lib/python2.7/dist-packages/lwp-0.6_-py2.7.egg/lwp/lxclite/__init__.py
d0727d87ca377ae832fa264bce90baed  /usr/local/lib/python2.7/dist-packages/lwp-0.6_-py2.7.egg/lwp/lxclite/__init__.py
# time lxc-ls --fancy | tail -n+3

(Output for 36 running and 17 stopped containers)

real    0m2.193s
user    0m0.148s
sys 0m0.116s
claudyus commented 10 years ago

Hello @kenzodeluxe can you retry with those new commits and close the bug if fixed? Thanks

kenzodeluxe commented 10 years ago

Hello @claudyus - thanks, initial loading now works as quickly as expected. However, the containers' memory usage isn't visible upon first load (seems to be loading in the background), and reloading the page is then again slow. In the profiling, I can see this:

(...)
1.2.3.4 - - [17/Sep/2014 09:33:47] "GET /_refresh_memory_host HTTP/1.1" 200 -
--------------------------------------------------------------------------------
PATH: '/_refresh_memory_containers'
         100552 function calls (100551 primitive calls) in 83.884 seconds

   Ordered by: internal time, call count
   List reduced from 341 to 30 due to restriction <30>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
      182   82.891    0.455   82.891    0.455 {method 'read' of 'file' objects}
      182    0.531    0.003    0.531    0.003 {posix.read}
      182    0.119    0.001    0.119    0.001 {posix.fork}
     7957    0.040    0.000    0.040    0.000 {posix.stat}
      182    0.035    0.000    0.702    0.004 /usr/lib/python2.7/subprocess.py:1187(_execute_child)
       36    0.027    0.001    0.060    0.002 /usr/lib/python2.7/ConfigParser.py:464(_read)
       73    0.020    0.000    0.611    0.008 /srv/LXC-Web-Panel/lwp/lxclite/__init__.py:93(ls)
       73    0.010    0.000    0.010    0.000 {posix.listdir}
      182    0.010    0.000    0.730    0.004 /usr/lib/python2.7/subprocess.py:650(__init__)
       36    0.009    0.000    0.329    0.009 /srv/LXC-Web-Panel/lwp/__init__.py:230(get_container_settings)
       37    0.008    0.000   82.943    2.242 /srv/LXC-Web-Panel/lwp/lxclite/__init__.py:111(listx)
     3764    0.008    0.000    0.008    0.000 {method 'match' of '_sre.SRE_Pattern' objects}
     4088    0.008    0.000    0.034    0.000 /usr/lib/python2.7/genericpath.py:38(isdir)
     8139    0.007    0.000    0.007    0.000 {method 'format' of 'str' objects}
      182    0.007    0.000   83.648    0.460 /usr/lib/python2.7/subprocess.py:544(check_output)
     3869    0.006    0.000    0.031    0.000 /usr/lib/python2.7/genericpath.py:26(isfile)
     5836    0.006    0.000    0.006    0.000 {method 'split' of 'str' objects}
      182    0.006    0.000    0.006    0.000 {posix.fdopen}
     2436    0.006    0.000    0.006    0.000 /usr/lib/python2.7/collections.py:54(__setitem__)
     1456    0.006    0.000    0.006    0.000 {fcntl.fcntl}
      429    0.005    0.000    0.012    0.000 /usr/lib/python2.7/ConfigParser.py:590(get)
      182    0.005    0.000   82.910    0.456 /usr/lib/python2.7/subprocess.py:768(communicate)
      546    0.005    0.000    0.005    0.000 {posix.close}
     2211    0.004    0.000    0.004    0.000 {method 'readline' of 'file' objects}
      546    0.004    0.000   83.429    0.153 /usr/lib/python2.7/subprocess.py:473(_eintr_retry_call)
     4088    0.004    0.000    0.006    0.000 /usr/lib/python2.7/stat.py:40(S_ISDIR)
      218    0.004    0.000    0.004    0.000 {method 'close' of 'file' objects}
     3869    0.004    0.000    0.005    0.000 /usr/lib/python2.7/stat.py:49(S_ISREG)
     7957    0.004    0.000    0.004    0.000 /usr/lib/python2.7/stat.py:24(S_IFMT)
      146    0.003    0.000   83.328    0.571 /srv/LXC-Web-Panel/lwp/lxclite/__init__.py:17(_run)

and

1.2.3.4 - - [17/Sep/2014 09:38:54] "GET /_refresh_memory_host HTTP/1.1" 200 -
--------------------------------------------------------------------------------
PATH: '/_refresh_memory_containers'
         100552 function calls (100551 primitive calls) in 84.750 seconds

   Ordered by: internal time, call count
   List reduced from 341 to 30 due to restriction <30>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
      182   83.767    0.460   83.767    0.460 {method 'read' of 'file' objects}
      182    0.529    0.003    0.529    0.003 {posix.read}
      182    0.120    0.001    0.120    0.001 {posix.fork}
     7957    0.037    0.000    0.037    0.000 {posix.stat}
      182    0.035    0.000    0.700    0.004 /usr/lib/python2.7/subprocess.py:1187(_execute_child)
       36    0.026    0.001    0.057    0.002 /usr/lib/python2.7/ConfigParser.py:464(_read)
       73    0.020    0.000    0.605    0.008 /srv/LXC-Web-Panel/lwp/lxclite/__init__.py:93(ls)
      182    0.009    0.000    0.729    0.004 /usr/lib/python2.7/subprocess.py:650(__init__)
       73    0.009    0.000    0.009    0.000 {posix.listdir}
       37    0.008    0.000   83.808    2.265 /srv/LXC-Web-Panel/lwp/lxclite/__init__.py:111(listx)
       36    0.008    0.000    0.324    0.009 /srv/LXC-Web-Panel/lwp/__init__.py:230(get_container_settings)
     8139    0.007    0.000    0.007    0.000 {method 'format' of 'str' objects}
      182    0.007    0.000   84.523    0.464 /usr/lib/python2.7/subprocess.py:544(check_output)
     3764    0.007    0.000    0.007    0.000 {method 'match' of '_sre.SRE_Pattern' objects}
     4088    0.007    0.000    0.032    0.000 /usr/lib/python2.7/genericpath.py:38(isdir)
     5836    0.006    0.000    0.006    0.000 {method 'split' of 'str' objects}
      182    0.006    0.000    0.006    0.000 {posix.fdopen}
     3869    0.006    0.000    0.029    0.000 /usr/lib/python2.7/genericpath.py:26(isfile)
     1456    0.006    0.000    0.006    0.000 {fcntl.fcntl}
     2436    0.005    0.000    0.005    0.000 /usr/lib/python2.7/collections.py:54(__setitem__)
      182    0.005    0.000   83.786    0.460 /usr/lib/python2.7/subprocess.py:768(communicate)
      429    0.005    0.000    0.011    0.000 /usr/lib/python2.7/ConfigParser.py:590(get)
      546    0.005    0.000   84.304    0.154 /usr/lib/python2.7/subprocess.py:473(_eintr_retry_call)
      546    0.004    0.000    0.004    0.000 {posix.close}
     4088    0.004    0.000    0.006    0.000 /usr/lib/python2.7/stat.py:40(S_ISDIR)
     3869    0.003    0.000    0.005    0.000 /usr/lib/python2.7/stat.py:49(S_ISREG)
       72    0.003    0.000    0.008    0.000 /usr/lib/python2.7/collections.py:38(__init__)
      218    0.003    0.000    0.003    0.000 {method 'close' of 'file' objects}
     2211    0.003    0.000    0.003    0.000 {method 'readline' of 'file' objects}
     7957    0.003    0.000    0.003    0.000 /usr/lib/python2.7/stat.py:24(S_IFMT)

--------------------------------------------------------------------------------

1.2.3.4 - - [17/Sep/2014 09:40:19] "GET /_refresh_memory_containers HTTP/1.1" 200 -
----------------------------------------
Exception happened during processing of request from ('1.2.3.4', 50204)
Traceback (most recent call last):
  File "/usr/lib/python2.7/SocketServer.py", line 295, in _handle_request_noblock
    self.process_request(request, client_address)
  File "/usr/lib/python2.7/SocketServer.py", line 321, in process_request
    self.finish_request(request, client_address)
  File "/usr/lib/python2.7/SocketServer.py", line 334, in finish_request
    self.RequestHandlerClass(request, client_address, self)
  File "/usr/lib/python2.7/SocketServer.py", line 653, in __init__
    self.finish()
  File "/usr/lib/python2.7/SocketServer.py", line 712, in finish
    self.wfile.close()
  File "/usr/lib/python2.7/socket.py", line 279, in close
    self.flush()
  File "/usr/lib/python2.7/socket.py", line 303, in flush
    self._sock.sendall(view[write_offset:write_offset+buffer_size])
error: [Errno 32] Broken pipe
----------------------------------------

(last entry most likely was due to logout and refreshing memory for containers taking too long) Is it possible that your fix is needed for other calls as well? Thanks!

claudyus commented 9 years ago

For this use case the only fix il multi threading server. see #59 for progress