python - Celery important slowdown on subprocess -


in context of web app, switched time consuming processing (latex rendering) "main program" celery.

and while worked fine on laptop during dev, on production server time needed processing have more tripled.

i narrowed down problem core processing in itself, , i've profiled it, i'm lost on cause such difference.

core processing

def process(content, passes=2):     tmp_dir = tempfile.mkdtemp()      open(os.path.join(tmp_dir, 'content.tex'), 'wb') f:         f.write(content.encode('utf-8'))      pr = cprofile.profile()     pr.enable()      _ in range(passes):         process = subprocess32.popen(             [                 '/path/to/lualatex',                 '--interaction',                 'nonstopmode',                 '--output-directory',                 tmp_dir,                 '--jobname',                 'output',                 'content.tex',             ],             cwd=tmp_dir,             stdout=fnull,             stderr=fnull,             bufsize=0,         )          process.wait()          if process.returncode != 0:             open(os.path.join(tmp_dir, 'output.log'), 'rb') f:                 raise latexerror(f.read())      pr.disable()     pr.dump_stats('/path/to/profile')      open(os.path.join(tmp_dir, 'output.pdf'), 'rb') pdf:         pdf_bytes = pdf.read()      shutil.rmtree(tmp_dir)     return pdf_bytes

profile "outside" celery

80 function calls in 1.973 seconds  ordered by: internal time  ncalls  tottime  percall  cumtime  percall filename:lineno(function)     2    1.969    0.985    1.969    0.985 {posix.waitpid}     2    0.002    0.001    0.002    0.001 {_posixsubprocess.fork_exec}     2    0.001    0.001    0.001    0.001 {posix.read}     2    0.000    0.000    0.003    0.002 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:1323(_execute_child)     2    0.000    0.000    1.969    0.985 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:1644(wait)     2    0.000    0.000    0.003    0.002 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:713(__init__)     4    0.000    0.000    1.970    0.493 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:540(_eintr_retry_call)     2    0.000    0.000    0.000    0.000 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:1578(_handle_exitstatus)     2    0.000    0.000    0.000    0.000 /home/admin/.envs/sydpnl/lib/python2.7/posixpath.py:127(dirname)     2    0.000    0.000    1.969    0.985 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:1629(_try_wait)     4    0.000    0.000    0.000    0.000 {posix.close}     2    0.000    0.000    0.000    0.000 {_posixsubprocess.cloexec_pipe}     1    0.000    0.000    0.000    0.000 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:872(__del__)     2    0.000    0.000    0.000    0.000 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:1245(_get_handles)    10    0.000    0.000    0.000    0.000 {isinstance}     2    0.000    0.000    0.000    0.000 {sorted}     2    0.000    0.000    0.000    0.000 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:525(_cleanup)     2    0.000    0.000    0.000    0.000 {posix.wifsignaled}     3    0.000    0.000    0.000    0.000 {method 'get' of 'dict' objects}     2    0.000    0.000    0.000    0.000 {method 'release' of 'thread.lock' objects}     2    0.000    0.000    0.000    0.000 {method 'rfind' of 'str' objects}     1    0.000    0.000    0.000    0.000 {getattr}     2    0.000    0.000    0.000    0.000 {thread.allocate_lock}     4    0.000    0.000    0.000    0.000 {method 'fileno' of 'file' objects}     2    0.000    0.000    0.000    0.000 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:1355(fs_encode)     2    0.000    0.000    0.000    0.000 {method 'rstrip' of 'str' objects}     2    0.000    0.000    0.000    0.000 {method 'acquire' of 'thread.lock' objects}     1    0.000    0.000    0.000    0.000 {range}     1    0.000    0.000    0.000    0.000 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:1593(_internal_poll)     2    0.000    0.000    0.000    0.000 {posix.wexitstatus}     2    0.000    0.000    0.000    0.000 {sys.getfilesystemencoding}     2    0.000    0.000    0.000    0.000 {len}     1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.profiler' objects}     2    0.000    0.000    0.000    0.000 {posix.wifexited}     2    0.000    0.000    0.000    0.000 {method 'add' of 'set' objects}

profile celery

80 function calls in 6.260 seconds  ordered by: internal time  ncalls  tottime  percall  cumtime  percall filename:lineno(function)     2    6.256    3.128    6.256    3.128 {posix.waitpid}     2    0.002    0.001    0.002    0.001 {_posixsubprocess.fork_exec}     2    0.001    0.001    0.001    0.001 {posix.read}     2    0.000    0.000    0.003    0.002 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:1323(_execute_child)     2    0.000    0.000    0.003    0.002 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:713(__init__)     2    0.000    0.000    6.256    3.128 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:1644(wait)     4    0.000    0.000    6.258    1.564 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:540(_eintr_retry_call)     4    0.000    0.000    0.000    0.000 {posix.close}     2    0.000    0.000    6.256    3.128 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:1629(_try_wait)     2    0.000    0.000    0.000    0.000 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:1578(_handle_exitstatus)     2    0.000    0.000    0.000    0.000 /home/admin/.envs/sydpnl/lib/python2.7/posixpath.py:127(dirname)     2    0.000    0.000    0.000    0.000 {_posixsubprocess.cloexec_pipe}     2    0.000    0.000    0.000    0.000 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:1245(_get_handles)     1    0.000    0.000    0.000    0.000 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:872(__del__)     2    0.000    0.000    0.000    0.000 {sorted}    10    0.000    0.000    0.000    0.000 {isinstance}     2    0.000    0.000    0.000    0.000 {posix.wifsignaled}     2    0.000    0.000    0.000    0.000 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:525(_cleanup)     3    0.000    0.000    0.000    0.000 {method 'get' of 'dict' objects}     2    0.000    0.000    0.000    0.000 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:1355(fs_encode)     2    0.000    0.000    0.000    0.000 {method 'release' of 'thread.lock' objects}     2    0.000    0.000    0.000    0.000 {method 'rfind' of 'str' objects}     4    0.000    0.000    0.000    0.000 {method 'fileno' of 'file' objects}     1    0.000    0.000    0.000    0.000 {getattr}     2    0.000    0.000    0.000    0.000 {thread.allocate_lock}     2    0.000    0.000    0.000    0.000 {method 'acquire' of 'thread.lock' objects}     2    0.000    0.000    0.000    0.000 {method 'add' of 'set' objects}     2    0.000    0.000    0.000    0.000 {method 'rstrip' of 'str' objects}     1    0.000    0.000    0.000    0.000 {range}     1    0.000    0.000    0.000    0.000 /home/admin/.envs/sydpnl/lib/python2.7/site-packages/subprocess32.py:1593(_internal_poll)     2    0.000    0.000    0.000    0.000 {posix.wexitstatus}     1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.profiler' objects}     2    0.000    0.000    0.000    0.000 {len}     2    0.000    0.000    0.000    0.000 {posix.wifexited}     2    0.000    0.000    0.000    0.000 {sys.getfilesystemencoding}

side facts

i'm running debian 7.8 , python 2.7.3 on server.

edit 01/4/2015

changed code , profile small bit highlight (i think) problem is.

i'm answering (and closing) question avoid https://xkcd.com/979/.

it seems problem coming process manager (circus) used manage celery process. circus reducing process resources somehow.

switching process manager resolved issue.


Comments

Post a Comment

Popular posts from this blog

Payment information shows nothing in one page checkout page magento -

i using magento ver. 1.9.1.0 want remove shipping information , shipping method step 1 page checkout page. changed code in core file like in app\code\core\mage\checkout\block\onepage.php public function getsteps() { $steps = array(); $stepcodes = $this->_getstepcodes(); /* remove shipping address , shipping method */ $excludestep=array_diff($stepcodes,array('shipping','shipping_method')); //$excludestep=$stepcodes; if ($this->iscustomerloggedin()) { $stepcodes = array_diff($excludestep, array('login')); } foreach ($excludestep $step) { $steps[$step] = $this->getcheckout()->getstepdata($step); } return $steps; } and in app\code\core\mage\checkout\controllers\onepagecontroller.php public function savebillingaction() { if ($this->_expireajax()) { return; } if ($this->getrequest()-...
Read more

tcpdump - How to check if server received packet (acknowledged) -

Image
i running tcpdump on server capture traffic between server (servera) , remote server (serverb). not know how read output tcpdump. point out if serverb acknowledging packets being sent servera being received serverb? here tcpdump log: 2015-03-31 11:32:18.038284 ip (tos 0x0, ttl 64, id 30781, offset 0, flags [df], proto tcp (6), length 60) servera.14033 > serverb.8004: flags [s], cksum 0x02bd (correct), seq 337482636, win 14600, options [mss 1460,nop,nop,ts val 506588081 ecr 0,nop,wscale 7], length 0 0x0000: 4500 003c 783d 4000 4006 bae4 0a04 7a0e e.. servera.14033: flags [s.], cksum 0x3b2a (correct), seq 1742982091, ack 337482637, win 4140, options [mss 1380,nop,wscale 0], length 0 0x0000: 4500 0030 5ff2 0000 f606 5d3b cefd b48a e..0_.....];.... 0x0010: 0a04 7a0e 1f44 36d1 67e3 cbcb 141d 938d ..z..d6.g....... 0x0020: 7012 102c 3b2a 0000 0204 0564 0103 0300 p..,;*.....d.... 2015-03-31 11:32:18.078622 ip (tos 0x0, ttl 64, id 30782, offset 0, flags [...
Read more