Celery: Warm shutdown does not work as expected since v4

[baratrion]

Steps to reproduce

Just fire up a simple celery configuration and try Ctrl^C to simulate warm shutdown behavior with latest Celery version. It [does not work as advertised]:(http://docs.celeryproject.org/en/latest/userguide/workers.html#stopping-the-worker) worker cannot wait for all tasks to be finished because main process terminates abruptly with an exception. See log output below where I submit a simple add task that sleeps 30secs several times so I could simulate a long running task and whether it would continue when the main process receives a SIGTERM.

[2018-12-26 14:59:10,082: INFO/ForkPoolWorker-1] celery_conf.add[a2f3a905-5d9d-416f-8a84-de8cf9c4f689]: Adding 4 + 2
[2018-12-26 14:59:10,083: INFO/ForkPoolWorker-1] celery_conf.add[a2f3a905-5d9d-416f-8a84-de8cf9c4f689]: Waiting 30 secs...
^C
worker: Hitting Ctrl+C again will terminate all running tasks!

worker: Warm shutdown (MainProcess)
[2018-12-26 14:59:13,061: DEBUG/MainProcess] | Worker: Closing Hub...
[2018-12-26 14:59:13,062: DEBUG/MainProcess] | Worker: Closing Pool...
[2018-12-26 14:59:13,062: DEBUG/MainProcess] | Worker: Closing Consumer...
[2018-12-26 14:59:13,062: DEBUG/MainProcess] | Worker: Stopping Consumer...
[2018-12-26 14:59:13,062: DEBUG/MainProcess] | Consumer: Closing Connection...
[2018-12-26 14:59:13,063: DEBUG/MainProcess] | Consumer: Closing Events...
[2018-12-26 14:59:13,063: DEBUG/MainProcess] | Consumer: Closing Mingle...
[2018-12-26 14:59:13,063: DEBUG/MainProcess] | Consumer: Closing Tasks...
[2018-12-26 14:59:13,063: DEBUG/MainProcess] | Consumer: Closing Control...
[2018-12-26 14:59:13,063: DEBUG/MainProcess] | Consumer: Closing Gossip...
[2018-12-26 14:59:13,063: DEBUG/MainProcess] | Consumer: Closing Heart...
[2018-12-26 14:59:13,063: DEBUG/MainProcess] | Consumer: Closing event loop...
[2018-12-26 14:59:13,063: DEBUG/MainProcess] | Consumer: Stopping event loop...
[2018-12-26 14:59:13,063: DEBUG/MainProcess] | Consumer: Stopping Heart...
[2018-12-26 14:59:13,065: DEBUG/MainProcess] | Consumer: Stopping Gossip...
[2018-12-26 14:59:13,067: ERROR/MainProcess] Error on stopping Gossip: ValueError('file descriptor cannot be a negative integer (-1)',)
Traceback (most recent call last):
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/worker.py", line 205, in start
    self.blueprint.start(self)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 119, in start
    step.start(parent)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 369, in start
    return self.obj.start()
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/consumer/consumer.py", line 317, in start
    blueprint.start(self)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 119, in start
    step.start(parent)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/consumer/consumer.py", line 593, in start
    c.loop(*c.loop_args())
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/loops.py", line 91, in asynloop
    next(loop)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/asynchronous/hub.py", line 306, in create_loop
    events = poll(poll_timeout)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/utils/eventio.py", line 217, in poll
    event_list = self._quick_poll(timeout)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/apps/worker.py", line 284, in _handle_request
    raise exc(exitcode)
celery.exceptions.WorkerShutdown: 1

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 151, in send_all
    fun(parent, *args)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 406, in stop
    self._close(c, True)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 419, in _close
    ignore_errors(c.connection, channel.close)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/common.py", line 298, in ignore_errors
    return fun(*args, **kwargs)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/transport/redis.py", line 852, in close
    self._disconnect_pools()
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/transport/redis.py", line 538, in _disconnect_pools
    async_pool.disconnect()
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/redis/connection.py", line 921, in disconnect
    connection.disconnect()
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/transport/redis.py", line 941, in disconnect
    channel._on_connection_disconnect(self)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/transport/redis.py", line 546, in _on_connection_disconnect
    self.connection.cycle._on_connection_disconnect(connection)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/transport/redis.py", line 1054, in _on_disconnect
    loop.remove(connection._sock)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/asynchronous/hub.py", line 181, in remove
    self._remove_from_loop(fd)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/asynchronous/hub.py", line 160, in _remove_from_loop
    self._unregister(fd)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/asynchronous/hub.py", line 243, in _unregister
    self.poller.unregister(fd)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/utils/eventio.py", line 209, in unregister
    self._quick_unregister(fd)
ValueError: file descriptor cannot be a negative integer (-1)
[2018-12-26 14:59:13,071: DEBUG/MainProcess] | Consumer: Stopping Control...
[2018-12-26 14:59:13,073: ERROR/MainProcess] Error on stopping Control: ValueError('file descriptor cannot be a negative integer (-1)',)
Traceback (most recent call last):
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/worker.py", line 205, in start
    self.blueprint.start(self)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 119, in start
    step.start(parent)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 369, in start
    return self.obj.start()
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/consumer/consumer.py", line 317, in start
    blueprint.start(self)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 119, in start
    step.start(parent)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/consumer/consumer.py", line 593, in start
    c.loop(*c.loop_args())
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/loops.py", line 91, in asynloop
    next(loop)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/asynchronous/hub.py", line 306, in create_loop
    events = poll(poll_timeout)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/utils/eventio.py", line 217, in poll
    event_list = self._quick_poll(timeout)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/apps/worker.py", line 284, in _handle_request
    raise exc(exitcode)
celery.exceptions.WorkerShutdown: 1

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 151, in send_all
    fun(parent, *args)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/pidbox.py", line 63, in stop
    self.consumer = self._close_channel(c)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/pidbox.py", line 71, in _close_channel
    ignore_errors(c, self.node.channel.close)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/common.py", line 298, in ignore_errors
    return fun(*args, **kwargs)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/transport/redis.py", line 852, in close
    self._disconnect_pools()
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/transport/redis.py", line 538, in _disconnect_pools
    async_pool.disconnect()
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/redis/connection.py", line 921, in disconnect
    connection.disconnect()
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/transport/redis.py", line 941, in disconnect
    channel._on_connection_disconnect(self)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/transport/redis.py", line 546, in _on_connection_disconnect
    self.connection.cycle._on_connection_disconnect(connection)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/transport/redis.py", line 1054, in _on_disconnect
    loop.remove(connection._sock)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/asynchronous/hub.py", line 181, in remove
    self._remove_from_loop(fd)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/asynchronous/hub.py", line 160, in _remove_from_loop
    self._unregister(fd)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/asynchronous/hub.py", line 243, in _unregister
    self.poller.unregister(fd)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/utils/eventio.py", line 209, in unregister
    self._quick_unregister(fd)
ValueError: file descriptor cannot be a negative integer (-1)
[2018-12-26 14:59:13,074: DEBUG/MainProcess] | Consumer: Stopping Tasks...
[2018-12-26 14:59:13,074: DEBUG/MainProcess] Canceling task consumer...
[2018-12-26 14:59:13,074: DEBUG/MainProcess] | Consumer: Stopping Mingle...
[2018-12-26 14:59:13,075: DEBUG/MainProcess] | Consumer: Stopping Events...
[2018-12-26 14:59:13,075: DEBUG/MainProcess] | Consumer: Stopping Connection...
[2018-12-26 14:59:13,075: DEBUG/MainProcess] | Worker: Stopping Pool...
[2018-12-26 14:59:13,079: ERROR/MainProcess] Error on stopping Pool: TypeError("can't pickle _thread.lock objects",)
Traceback (most recent call last):
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/worker.py", line 205, in start
    self.blueprint.start(self)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 119, in start
    step.start(parent)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 369, in start
    return self.obj.start()
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/consumer/consumer.py", line 317, in start
    blueprint.start(self)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 119, in start
    step.start(parent)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/consumer/consumer.py", line 593, in start
    c.loop(*c.loop_args())
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/loops.py", line 91, in asynloop
    next(loop)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/asynchronous/hub.py", line 306, in create_loop
    events = poll(poll_timeout)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/utils/eventio.py", line 217, in poll
    event_list = self._quick_poll(timeout)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/apps/worker.py", line 284, in _handle_request
    raise exc(exitcode)
celery.exceptions.WorkerShutdown: 1

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 151, in send_all
    fun(parent, *args)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 373, in stop
    return self.obj.stop()
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/concurrency/base.py", line 122, in stop
    self.on_stop()
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/concurrency/prefork.py", line 140, in on_stop
    self._pool.join()
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/billiard/pool.py", line 1578, in join
    stop_if_not_current(self._result_handler)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/billiard/pool.py", line 143, in stop_if_not_current
    thread.stop(timeout)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/billiard/pool.py", line 500, in stop
    self.on_stop_not_started()
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/concurrency/asynpool.py", line 332, in on_stop_not_started
    check_timeouts()
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/billiard/pool.py", line 744, in handle_event
    next(self._it)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/billiard/pool.py", line 697, in handle_timeouts
    cache = copy.deepcopy(self.cache)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/copy.py", line 150, in deepcopy
    y = copier(x, memo)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/copy.py", line 240, in _deepcopy_dict
    y[deepcopy(key, memo)] = deepcopy(value, memo)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/copy.py", line 180, in deepcopy
    y = _reconstruct(x, memo, *rv)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/copy.py", line 280, in _reconstruct
    state = deepcopy(state, memo)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/copy.py", line 150, in deepcopy
    y = copier(x, memo)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/copy.py", line 240, in _deepcopy_dict
    y[deepcopy(key, memo)] = deepcopy(value, memo)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/copy.py", line 180, in deepcopy
    y = _reconstruct(x, memo, *rv)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/copy.py", line 280, in _reconstruct
    state = deepcopy(state, memo)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/copy.py", line 150, in deepcopy
    y = copier(x, memo)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/copy.py", line 240, in _deepcopy_dict
    y[deepcopy(key, memo)] = deepcopy(value, memo)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/copy.py", line 180, in deepcopy
    y = _reconstruct(x, memo, *rv)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/copy.py", line 280, in _reconstruct
    state = deepcopy(state, memo)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/copy.py", line 150, in deepcopy
    y = copier(x, memo)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/copy.py", line 240, in _deepcopy_dict
    y[deepcopy(key, memo)] = deepcopy(value, memo)
  File "/Users/catalbas/envs/kfd-celery/lib/python3.6/copy.py", line 169, in deepcopy
    rv = reductor(4)
TypeError: can't pickle _thread.lock objects
[2018-12-26 14:59:13,083: DEBUG/MainProcess] | Worker: Stopping Hub...
[2018-12-26 14:59:13,083: DEBUG/MainProcess] | Consumer: Shutdown Heart...
[2018-12-26 14:59:13,083: DEBUG/MainProcess] | Consumer: Shutdown Gossip...
[2018-12-26 14:59:13,084: WARNING/MainProcess] Traceback (most recent call last):
[2018-12-26 14:59:13,084: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/worker.py", line 205, in start
[2018-12-26 14:59:13,084: WARNING/MainProcess] self.blueprint.start(self)
[2018-12-26 14:59:13,084: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 119, in start
[2018-12-26 14:59:13,085: WARNING/MainProcess] step.start(parent)
[2018-12-26 14:59:13,085: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 369, in start
[2018-12-26 14:59:13,085: WARNING/MainProcess] return self.obj.start()
[2018-12-26 14:59:13,085: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/consumer/consumer.py", line 317, in start
[2018-12-26 14:59:13,086: WARNING/MainProcess] blueprint.start(self)
[2018-12-26 14:59:13,086: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 119, in start
[2018-12-26 14:59:13,086: WARNING/MainProcess] step.start(parent)
[2018-12-26 14:59:13,086: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/consumer/consumer.py", line 593, in start
[2018-12-26 14:59:13,087: WARNING/MainProcess] c.loop(*c.loop_args())
[2018-12-26 14:59:13,087: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/loops.py", line 91, in asynloop
[2018-12-26 14:59:13,088: WARNING/MainProcess] next(loop)
[2018-12-26 14:59:13,088: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/asynchronous/hub.py", line 306, in create_loop
[2018-12-26 14:59:13,088: WARNING/MainProcess] events = poll(poll_timeout)
[2018-12-26 14:59:13,088: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/utils/eventio.py", line 217, in poll
[2018-12-26 14:59:13,088: WARNING/MainProcess] event_list = self._quick_poll(timeout)
[2018-12-26 14:59:13,089: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/apps/worker.py", line 284, in _handle_request
[2018-12-26 14:59:13,089: WARNING/MainProcess] raise exc(exitcode)
[2018-12-26 14:59:13,089: WARNING/MainProcess] celery.exceptions
[2018-12-26 14:59:13,089: WARNING/MainProcess] .
[2018-12-26 14:59:13,089: WARNING/MainProcess] WorkerShutdown
[2018-12-26 14:59:13,089: WARNING/MainProcess] :
[2018-12-26 14:59:13,090: WARNING/MainProcess] 1
[2018-12-26 14:59:13,090: WARNING/MainProcess] During handling of the above exception, another exception occurred:
[2018-12-26 14:59:13,090: WARNING/MainProcess] Traceback (most recent call last):
[2018-12-26 14:59:13,090: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/bin/celery", line 11, in <module>
[2018-12-26 14:59:13,090: WARNING/MainProcess] sys.exit(main())
[2018-12-26 14:59:13,090: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/__main__.py", line 16, in main
[2018-12-26 14:59:13,091: WARNING/MainProcess] _main()
[2018-12-26 14:59:13,091: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bin/celery.py", line 322, in main
[2018-12-26 14:59:13,091: WARNING/MainProcess] cmd.execute_from_commandline(argv)
[2018-12-26 14:59:13,091: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bin/celery.py", line 496, in execute_from_commandline
[2018-12-26 14:59:13,092: WARNING/MainProcess] super(CeleryCommand, self).execute_from_commandline(argv)))
[2018-12-26 14:59:13,092: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bin/base.py", line 275, in execute_from_commandline
[2018-12-26 14:59:13,092: WARNING/MainProcess] return self.handle_argv(self.prog_name, argv[1:])
[2018-12-26 14:59:13,092: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bin/celery.py", line 488, in handle_argv
[2018-12-26 14:59:13,093: WARNING/MainProcess] return self.execute(command, argv)
[2018-12-26 14:59:13,093: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bin/celery.py", line 420, in execute
[2018-12-26 14:59:13,094: WARNING/MainProcess] ).run_from_argv(self.prog_name, argv[1:], command=argv[0])
[2018-12-26 14:59:13,094: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bin/worker.py", line 223, in run_from_argv
[2018-12-26 14:59:13,095: WARNING/MainProcess] return self(*args, **options)
[2018-12-26 14:59:13,095: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bin/base.py", line 238, in __call__
[2018-12-26 14:59:13,096: WARNING/MainProcess] ret = self.run(*args, **kwargs)
[2018-12-26 14:59:13,096: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bin/worker.py", line 258, in run
[2018-12-26 14:59:13,096: WARNING/MainProcess] worker.start()
[2018-12-26 14:59:13,097: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/worker.py", line 212, in start
[2018-12-26 14:59:13,097: WARNING/MainProcess] self.stop(exitcode=exc.code)
[2018-12-26 14:59:13,097: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/worker.py", line 253, in stop
[2018-12-26 14:59:13,097: WARNING/MainProcess] self._shutdown(warm=True)
[2018-12-26 14:59:13,097: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/worker.py", line 268, in _shutdown
[2018-12-26 14:59:13,098: WARNING/MainProcess] self.blueprint.stop(self, terminate=not warm)
[2018-12-26 14:59:13,098: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 177, in stop
[2018-12-26 14:59:13,098: WARNING/MainProcess] self.on_stopped()
[2018-12-26 14:59:13,098: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/worker.py", line 164, in on_stopped
[2018-12-26 14:59:13,099: WARNING/MainProcess] self.consumer.shutdown()
[2018-12-26 14:59:13,099: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/consumer/consumer.py", line 352, in shutdown
[2018-12-26 14:59:13,100: WARNING/MainProcess] self.blueprint.shutdown(self)
[2018-12-26 14:59:13,100: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/worker/consumer/consumer.py", line 159, in shutdown
[2018-12-26 14:59:13,100: WARNING/MainProcess] self.send_all(parent, 'shutdown')
[2018-12-26 14:59:13,100: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 151, in send_all
[2018-12-26 14:59:13,101: WARNING/MainProcess] fun(parent, *args)
[2018-12-26 14:59:13,101: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 409, in shutdown
[2018-12-26 14:59:13,101: WARNING/MainProcess] self._close(c, False)
[2018-12-26 14:59:13,101: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/celery/bootsteps.py", line 419, in _close
[2018-12-26 14:59:13,102: WARNING/MainProcess] ignore_errors(c.connection, channel.close)
[2018-12-26 14:59:13,102: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/common.py", line 298, in ignore_errors
[2018-12-26 14:59:13,102: WARNING/MainProcess] return fun(*args, **kwargs)
[2018-12-26 14:59:13,102: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/transport/redis.py", line 853, in close
[2018-12-26 14:59:13,103: WARNING/MainProcess] self._close_clients()
[2018-12-26 14:59:13,103: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/transport/redis.py", line 862, in _close_clients
[2018-12-26 14:59:13,104: WARNING/MainProcess] connection.disconnect()
[2018-12-26 14:59:13,104: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/transport/redis.py", line 941, in disconnect
[2018-12-26 14:59:13,105: WARNING/MainProcess] channel._on_connection_disconnect(self)
[2018-12-26 14:59:13,105: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/transport/redis.py", line 546, in _on_connection_disconnect
[2018-12-26 14:59:13,106: WARNING/MainProcess] self.connection.cycle._on_connection_disconnect(connection)
[2018-12-26 14:59:13,106: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/transport/redis.py", line 1054, in _on_disconnect
[2018-12-26 14:59:13,106: WARNING/MainProcess] loop.remove(connection._sock)
[2018-12-26 14:59:13,107: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/asynchronous/hub.py", line 181, in remove
[2018-12-26 14:59:13,107: WARNING/MainProcess] self._remove_from_loop(fd)
[2018-12-26 14:59:13,107: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/asynchronous/hub.py", line 160, in _remove_from_loop
[2018-12-26 14:59:13,107: WARNING/MainProcess] self._unregister(fd)
[2018-12-26 14:59:13,107: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/asynchronous/hub.py", line 243, in _unregister
[2018-12-26 14:59:13,108: WARNING/MainProcess] self.poller.unregister(fd)
[2018-12-26 14:59:13,108: WARNING/MainProcess] File "/Users/catalbas/envs/kfd-celery/lib/python3.6/site-packages/kombu/utils/eventio.py", line 209, in unregister
[2018-12-26 14:59:13,108: WARNING/MainProcess] self._quick_unregister(fd)
[2018-12-26 14:59:13,108: WARNING/MainProcess] ValueError
[2018-12-26 14:59:13,109: WARNING/MainProcess] :
[2018-12-26 14:59:13,109: WARNING/MainProcess] file descriptor cannot be a negative integer (-1)
[2018-12-26 14:59:13,109: DEBUG/MainProcess] removing tasks from inqueue until task handler finished

I have tried exact same setup with version 3.1.25 and it seems to be working just fine, main worker waits for all tasks to complete and then terminates.

This has become a critical issue for us since upgraded to latest Celery version as we're not able to deploy reliably to workers anymore. Although recommended, unfortunately not all of our tasks are idempotent so a task that gets killed in the middle of execution is a big issue.

[baratrion]

OK. I think we got the hang of it. The problem is with billiard's latest version 3.5.0.5, specifically this change broke the warm shutdown: https://github.com/celery/billiard/compare/v3.5.0.4...v3.5.0.5#diff-42cbdfeee4eeeb2688454e975c2d18ffR697

Falling back to 3.5.0.4 seemed to have worked!

[clokep]

I think this is a duplicate of celery/billiard#260.

[auvipy]

this should be fixed with billiard 3.6 and celery 4.3