<p dir="auto">Hi All,</p>
<p dir="auto">i am using celery 3.1.2(ciaper) with kombu 3.0.21. WHen I tried to restart celery as it was in hung state, it printed below output in log, later it stopped responding, Can anyone please advice how to start celery without killing it.</p>
<p dir="auto">[2014-08-04 22:48:53,979: WARNING/MainProcess] consumer: Connection to broker lost. Trying to re-establish the connection...<br>
Traceback (most recent call last):<br>
File "/usr/local/python/lib/python2.7/site-packages/celery/worker/consumer.py", line 278, in start<br>
blueprint.start(self)<br>
File "/usr/local/python/lib/python2.7/site-packages/celery/bootsteps.py", line 123, in start<br>
step.start(parent)<br>
File "/usr/local/python/lib/python2.7/site-packages/celery/worker/consumer.py", line 821, in start<br>
c.loop(*c.loop_args())<br>
File "/usr/local/python/lib/python2.7/site-packages/celery/worker/loops.py", line 70, in asynloop<br>
next(loop)<br>
File "/usr/local/python/lib/python2.7/site-packages/kombu/async/hub.py", line 267, in create_loop<br>
tick_callback()<br>
File "/usr/local/python/lib/python2.7/site-packages/kombu/transport/redis.py", line 940, in on_poll_start<br>
[add_reader(fd, on_readable, fd) for fd in cycle.fds]<br>
File "/usr/local/python/lib/python2.7/site-packages/kombu/async/hub.py", line 201, in add_reader<br>
return self.add(fds, callback, READ | ERR, args)<br>
File "/usr/local/python/lib/python2.7/site-packages/kombu/async/hub.py", line 152, in add<br>
self.poller.register(fd, flags)<br>
File "/usr/local/python/lib/python2.7/site-packages/kombu/utils/eventio.py", line 78, in register<br>
self._epoll.register(fd, events)<br>
IOError: [Errno 9] Bad file descriptor<br>
[2014-08-04 22:48:53,997: WARNING/MainProcess] Restoring 45 unacknowledged message(s).</p>
<p dir="auto">Srikanth</p>
<p dir="auto">Hello,</p>
<p dir="auto">We're using Celery 3.1.6, and one of our queues is using 100% CPU for the master process.  ps shows:</p>
<div class="snippet-clipboard-content notranslate position-relative overflow-auto" data-snippet-clipboard-copy-content="root      6960 59.2  0.7 160680 51628 ?        Rs   Feb01 2319:49 /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root     32727  0.3  1.1 266008 82860 ?        S    Feb02   6:29  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root     32729  0.2  1.1 265184 82040 ?        S    Feb02   5:54  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root     32730  0.2  1.4 282868 99788 ?        S    Feb02   5:29  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root       750  0.1  1.5 296584 113100 ?       S    Feb02   3:03  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root       917  0.2  1.1 262044 78888 ?        S    Feb02   6:00  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root      1873  0.0  1.2 269460 86276 ?        S    Feb02   1:34  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root      1875  0.0  1.4 285568 102384 ?       S    Feb02   0:36  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root      2347  0.0  0.8 245448 60984 ?        S    Feb02   1:47  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root      2348  0.0  0.8 247760 63356 ?        S    Feb02   1:33  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root      2362  0.0  1.0 257880 73416 ?        S    Feb02   1:09  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO"><pre class="notranslate"><code class="notranslate">root      6960 59.2  0.7 160680 51628 ?        Rs   Feb01 2319:49 /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root     32727  0.3  1.1 266008 82860 ?        S    Feb02   6:29  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root     32729  0.2  1.1 265184 82040 ?        S    Feb02   5:54  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root     32730  0.2  1.4 282868 99788 ?        S    Feb02   5:29  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root       750  0.1  1.5 296584 113100 ?       S    Feb02   3:03  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root       917  0.2  1.1 262044 78888 ?        S    Feb02   6:00  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root      1873  0.0  1.2 269460 86276 ?        S    Feb02   1:34  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root      1875  0.0  1.4 285568 102384 ?       S    Feb02   0:36  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root      2347  0.0  0.8 245448 60984 ?        S    Feb02   1:47  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root      2348  0.0  0.8 247760 63356 ?        S    Feb02   1:33  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
root      2362  0.0  1.0 257880 73416 ?        S    Feb02   1:09  \_ /$VENV/bin/python /$VENV/manage.py celery worker -Q ads -P prefork --autoscale=10,5 -n $NAME --settings=settings -l INFO
</code></pre></div>
<p dir="auto">And strace is more interesting.  It shows the following loop as the only thing happening in the parent:</p>
<div class="snippet-clipboard-content notranslate position-relative overflow-auto" data-snippet-clipboard-copy-content="gettimeofday({1391450996, 406286}, NULL) = 0
epoll_wait(4, {{EPOLLIN, {u32=6, u64=22205092589469702}}}, 1023, 1000) = 1
epoll_ctl(4, EPOLL_CTL_DEL, 34, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_DEL, 67, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_DEL, 68, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_DEL, 38, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_DEL, 10, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_DEL, 53, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_DEL, 26, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_DEL, 59, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_DEL, 30, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_DEL, 63, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_ADD, 51, {EPOLLIN|EPOLLERR|EPOLLHUP, {u32=51, u64=22205092589469747}}) = -1 EEXIST (File exists)
epoll_ctl(4, EPOLL_CTL_ADD, 52, {EPOLLIN|EPOLLERR|EPOLLHUP, {u32=52, u64=22205092589469748}}) = -1 EEXIST (File exists)
epoll_ctl(4, EPOLL_CTL_ADD, 6, {EPOLLIN|EPOLLERR|EPOLLHUP, {u32=6, u64=22205092589469702}}) = -1 EEXIST (File exists)"><pre class="notranslate"><code class="notranslate">gettimeofday({1391450996, 406286}, NULL) = 0
epoll_wait(4, {{EPOLLIN, {u32=6, u64=22205092589469702}}}, 1023, 1000) = 1
epoll_ctl(4, EPOLL_CTL_DEL, 34, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_DEL, 67, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_DEL, 68, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_DEL, 38, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_DEL, 10, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_DEL, 53, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_DEL, 26, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_DEL, 59, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_DEL, 30, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_DEL, 63, {EPOLLRDNORM|EPOLLRDBAND|EPOLLWRNORM|EPOLLMSG|0x4e9020, {u32=0, u64=22205092589469696}}) = -1 ENOENT (No such file or directory)
epoll_ctl(4, EPOLL_CTL_ADD, 51, {EPOLLIN|EPOLLERR|EPOLLHUP, {u32=51, u64=22205092589469747}}) = -1 EEXIST (File exists)
epoll_ctl(4, EPOLL_CTL_ADD, 52, {EPOLLIN|EPOLLERR|EPOLLHUP, {u32=52, u64=22205092589469748}}) = -1 EEXIST (File exists)
epoll_ctl(4, EPOLL_CTL_ADD, 6, {EPOLLIN|EPOLLERR|EPOLLHUP, {u32=6, u64=22205092589469702}}) = -1 EEXIST (File exists)
</code></pre></div>
<p dir="auto">Those FDs are pipes according to <code class="notranslate">/proc/$PID/fd</code>.  (strace also shows heartbeat/worker chatter from other processes read via the redis socket).</p>
<p dir="auto">Restarting the upstart job caused the worker to begin consuming tasks again.  I think this is some corner case that isn't being handled well.  Kombu's eventio.py has the following:</p>
<div class="highlight highlight-source-python notranslate position-relative overflow-auto" dir="auto" data-snippet-clipboard-copy-content="class _epoll(Poller):
    # ...
    def register(self, fd, events):
        try:
            self._epoll.register(fd, events)
        except Exception as exc:
            if get_errno(exc) != errno.EEXIST:
                raise
    def unregister(self, fd):
        try:
            self._epoll.unregister(fd)
        except (socket.error, ValueError, KeyError):
            pass
        except (IOError, OSError) as exc:
            if get_errno(exc) != errno.ENOENT:
                raise"><pre class="notranslate"><span class="pl-k">class</span> <span class="pl-s1">_epoll</span>(<span class="pl-v">Poller</span>):
    <span class="pl-c"># ...</span>
    <span class="pl-k">def</span> <span class="pl-en">register</span>(<span class="pl-s1">self</span>, <span class="pl-s1">fd</span>, <span class="pl-s1">events</span>):
        <span class="pl-k">try</span>:
            <span class="pl-s1">self</span>.<span class="pl-s1">_epoll</span>.<span class="pl-en">register</span>(<span class="pl-s1">fd</span>, <span class="pl-s1">events</span>)
        <span class="pl-k">except</span> <span class="pl-v">Exception</span> <span class="pl-k">as</span> <span class="pl-s1">exc</span>:
            <span class="pl-k">if</span> <span class="pl-en">get_errno</span>(<span class="pl-s1">exc</span>) <span class="pl-c1">!=</span> <span class="pl-s1">errno</span>.<span class="pl-v">EEXIST</span>:
                <span class="pl-k">raise</span>
    <span class="pl-k">def</span> <span class="pl-en">unregister</span>(<span class="pl-s1">self</span>, <span class="pl-s1">fd</span>):
        <span class="pl-k">try</span>:
            <span class="pl-s1">self</span>.<span class="pl-s1">_epoll</span>.<span class="pl-en">unregister</span>(<span class="pl-s1">fd</span>)
        <span class="pl-k">except</span> (<span class="pl-s1">socket</span>.<span class="pl-s1">error</span>, <span class="pl-v">ValueError</span>, <span class="pl-v">KeyError</span>):
            <span class="pl-k">pass</span>
        <span class="pl-k">except</span> (<span class="pl-v">IOError</span>, <span class="pl-v">OSError</span>) <span class="pl-k">as</span> <span class="pl-s1">exc</span>:
            <span class="pl-k">if</span> <span class="pl-en">get_errno</span>(<span class="pl-s1">exc</span>) <span class="pl-c1">!=</span> <span class="pl-s1">errno</span>.<span class="pl-v">ENOENT</span>:
                <span class="pl-k">raise</span></pre></div>
<p dir="auto">We are specifically checking for ENOENT and EEXIST here and silently dropping the exception - it seems like this might be causing a problem for someone further down the stack, but I'm not familiar with this part of celery.</p>
<p dir="auto">Any help/pointers appreciated.  Let me know what other info is useful as well.</p>